+ [07:12:12 UTC] Running lb suite test: subsetting_test
+ [07:12:12 UTC] Test driver flags for subsetting_test:
--flagfile=config/grpc-testing.cfg
--kube_context=gke_grpc-testing_us-central1-a_psm-interop-lb-primary
--force_cleanup
--collect_app_logs
--log_dir=/tmpfs/src/artifacts/grpc/node/master/xds_k8s_lb/subsetting_test
--xml_output_file=/tmpfs/src/artifacts/grpc/node/master/xds_k8s_lb/subsetting_test/sponge_log.xml
--testing_version=dev-master
--client_image=us-docker.pkg.dev/grpc-testing/psm-interop/node-client:c6391f3db078215cdfa8fdab35c5bbc2785f7956
--server_image=us-docker.pkg.dev/grpc-testing/psm-interop/java-server:canonical
--secondary_kube_context=gke_grpc-testing_us-west1-b_psm-interop-lb-secondary
+ [07:12:12 UTC] python -m tests.subsetting_test --flagfile=config/grpc-testing.cfg --kube_context=gke_grpc-testing_us-central1-a_psm-interop-lb-primary --force_cleanup --collect_app_logs --log_dir=/tmpfs/src/artifacts/grpc/node/master/xds_k8s_lb/subsetting_test --xml_output_file=/tmpfs/src/artifacts/grpc/node/master/xds_k8s_lb/subsetting_test/sponge_log.xml --testing_version=dev-master --client_image=us-docker.pkg.dev/grpc-testing/psm-interop/node-client:c6391f3db078215cdfa8fdab35c5bbc2785f7956 --server_image=us-docker.pkg.dev/grpc-testing/psm-interop/java-server:canonical --secondary_kube_context=gke_grpc-testing_us-west1-b_psm-interop-lb-secondary
Running tests under Python 3.10.12: /tmp/tmp.AHy4VRCzAB/psm-interop/venv/bin/python
I0427 07:12:13.571059 135711971115008 xds_k8s_testcase.py:162] ----- Testing SubsettingTest -----
I0427 07:12:13.571166 135711971115008 xds_k8s_testcase.py:163] Logs timezone: UTC
I0427 07:12:13.571338 135711971115008 xds_k8s_testcase.py:111] Detected language and version: TestConfig(client_lang='node', server_lang='java', version='dev-master')
I0427 07:12:13.584826 135711971115008 k8s.py:243] Using kubernetes context "gke_grpc-testing_us-central1-a_psm-interop-lb-primary", active host: https://35.238.98.54
I0427 07:12:13.598238 135711971115008 k8s.py:243] Using kubernetes context "gke_grpc-testing_us-west1-b_psm-interop-lb-secondary", active host: https://35.227.140.120
[ RUN ] SubsettingTest.test_subsetting_basic
I0427 07:12:13.602038 135711971115008 xds_k8s_testcase.py:736] Test run resource prefix: psm-interop, suffix: 20240427-0712-rj6ui
I0427 07:12:13.883687 135711971115008 logs.py:31] Log root dir: /tmpfs/src/artifacts/grpc/node/master/xds_k8s_lb/subsetting_test
I0427 07:12:14.152826 135711971115008 xds_k8s_testcase.py:731] Found unused xds port: 13901
I0427 07:12:14.153234 135711971115008 xds_k8s_testcase.py:299] --- Starting subTest SubsettingTest.test_subsetting_basic.00_create_health_check ---
I0427 07:12:14.153356 135711971115008 traffic_director.py:191] Creating GRPC Health Check "psm-interop-health-check-20240427-0712-rj6ui"
I0427 07:12:14.156188 135711971115008 compute.py:537] Creating compute resource:
---
grpcHealthCheck:
portSpecification: USE_SERVING_PORT
name: psm-interop-health-check-20240427-0712-rj6ui
type: GRPC
...
I0427 07:12:14.946844 135711971115008 compute.py:614] Waiting 600 sec for compute operation id: operation-1714201934204-6170ebd5c8ebe-b1afdcf1-6797fab8
I0427 07:12:17.209044 135711971115008 xds_k8s_testcase.py:304] --- Finished subTest SubsettingTest.test_subsetting_basic.00_create_health_check ---
I0427 07:12:17.209241 135711971115008 xds_k8s_testcase.py:299] --- Starting subTest SubsettingTest.test_subsetting_basic.01_create_backend_services ---
I0427 07:12:17.209334 135711971115008 traffic_director.py:218] Creating GRPC Backend Service "psm-interop-backend-service-20240427-0712-rj6ui"
I0427 07:12:17.217066 135711971115008 compute.py:537] Creating compute resource:
---
healthChecks:
- https://www.googleapis.com/compute/alpha/projects/grpc-testing/global/healthChecks/psm-interop-health-check-20240427-0712-rj6ui
loadBalancingScheme: INTERNAL_SELF_MANAGED
name: psm-interop-backend-service-20240427-0712-rj6ui
protocol: GRPC
subsetting:
policy: CONSISTENT_HASH_SUBSETTING
subsetSize: 4
...
I0427 07:12:17.994876 135711971115008 compute.py:614] Waiting 600 sec for compute operation id: operation-1714201937219-6170ebd8a8e76-5183059f-b532de17
I0427 07:12:39.695245 135711971115008 xds_k8s_testcase.py:304] --- Finished subTest SubsettingTest.test_subsetting_basic.01_create_backend_services ---
I0427 07:12:39.695469 135711971115008 xds_k8s_testcase.py:299] --- Starting subTest SubsettingTest.test_subsetting_basic.02_create_url_map ---
I0427 07:12:39.695578 135711971115008 traffic_director.py:479] Creating URL map "psm-interop-url-map-20240427-0712-rj6ui": psm-grpc-server:13901 -> psm-interop-backend-service-20240427-0712-rj6ui
I0427 07:12:39.703910 135711971115008 compute.py:537] Creating compute resource:
---
defaultService: https://www.googleapis.com/compute/alpha/projects/grpc-testing/global/backendServices/psm-interop-backend-service-20240427-0712-rj6ui
hostRules:
- hosts:
- psm-grpc-server:13901
pathMatcher: psm-interop-path-matcher-20240427-0712-rj6ui
name: psm-interop-url-map-20240427-0712-rj6ui
pathMatchers:
- defaultService: https://www.googleapis.com/compute/alpha/projects/grpc-testing/global/backendServices/psm-interop-backend-service-20240427-0712-rj6ui
name: psm-interop-path-matcher-20240427-0712-rj6ui
...
I0427 07:12:40.337866 135711971115008 compute.py:614] Waiting 600 sec for compute operation id: operation-1714201959706-6170ebee1adff-f8087a8a-f83c08db
I0427 07:12:42.583690 135711971115008 xds_k8s_testcase.py:304] --- Finished subTest SubsettingTest.test_subsetting_basic.02_create_url_map ---
I0427 07:12:42.583921 135711971115008 xds_k8s_testcase.py:299] --- Starting subTest SubsettingTest.test_subsetting_basic.03_create_target_proxy ---
I0427 07:12:42.584043 135711971115008 traffic_director.py:578] Creating target psm-interop-target-proxy-20240427-0712-rj6ui proxy "GRPC" to URL map psm-interop-url-map-20240427-0712-rj6ui
I0427 07:12:42.585787 135711971115008 compute.py:537] Creating compute resource:
---
name: psm-interop-target-proxy-20240427-0712-rj6ui
url_map: https://www.googleapis.com/compute/alpha/projects/grpc-testing/global/urlMaps/psm-interop-url-map-20240427-0712-rj6ui
validate_for_proxyless: true
...
I0427 07:12:43.181981 135711971115008 compute.py:614] Waiting 600 sec for compute operation id: operation-1714201962587-6170ebf0da6ec-7916465b-f9b02423
I0427 07:12:45.450025 135711971115008 xds_k8s_testcase.py:304] --- Finished subTest SubsettingTest.test_subsetting_basic.03_create_target_proxy ---
I0427 07:12:45.450232 135711971115008 xds_k8s_testcase.py:299] --- Starting subTest SubsettingTest.test_subsetting_basic.04_create_forwarding_rule ---
I0427 07:12:45.450354 135711971115008 traffic_director.py:654] Creating forwarding rule "psm-interop-forwarding-rule-20240427-0712-rj6ui" in network "default-vpc": 0.0.0.0:13901 -> https://www.googleapis.com/compute/alpha/projects/grpc-testing/global/targetGrpcProxies/psm-interop-target-proxy-20240427-0712-rj6ui
I0427 07:12:45.452343 135711971115008 compute.py:537] Creating compute resource:
---
IPAddress: 0.0.0.0
loadBalancingScheme: INTERNAL_SELF_MANAGED
name: psm-interop-forwarding-rule-20240427-0712-rj6ui
network: global/networks/default-vpc
portRange: 13901
target: https://www.googleapis.com/compute/alpha/projects/grpc-testing/global/targetGrpcProxies/psm-interop-target-proxy-20240427-0712-rj6ui
...
I0427 07:12:46.462087 135711971115008 compute.py:614] Waiting 600 sec for compute operation id: operation-1714201965454-6170ebf39649a-8c28889d-49ed5855
I0427 07:13:18.475205 135711971115008 xds_k8s_testcase.py:304] --- Finished subTest SubsettingTest.test_subsetting_basic.04_create_forwarding_rule ---
I0427 07:13:18.475407 135711971115008 xds_k8s_testcase.py:299] --- Starting subTest SubsettingTest.test_subsetting_basic.05_start_test_servers ---
I0427 07:13:18.475507 135711971115008 k8s_xds_server_runner.py:186] Deploying xDS test server "psm-grpc-server" to k8s namespace psm-interop-server-20240427-0712-rj6ui: test_port=8080 maintenance_port=8080 secure_mode=False replica_count=8
I0427 07:13:18.475727 135711971115008 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-server:
https://console.cloud.google.com/logs/query;query=resource.type%3D%22k8s_container%22%0Aresource.labels.project_id%3D%22grpc-testing%22%0Aresource.labels.container_name%3D%22psm-grpc-server%22%0Aresource.labels.namespace_name%3D%22psm-interop-server-20240427-0712-rj6ui%22;timeRange=2024-04-27T07:13:18.475602Z%2F2024-04-27T07:43:18.475602Z?project=grpc-testing
I0427 07:13:18.479727 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/namespace.yaml:
---
apiVersion: v1
kind: Namespace
metadata:
name: psm-interop-server-20240427-0712-rj6ui
labels:
name: psm-interop-server-20240427-0712-rj6ui
owner: xds-k8s-interop-test
...
I0427 07:13:18.626076 135711971115008 k8s_base_runner.py:367] Namespace psm-interop-server-20240427-0712-rj6ui created
I0427 07:13:18.628238 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/server.service.yaml:
---
apiVersion: v1
kind: Service
metadata:
name: psm-grpc-server
namespace: psm-interop-server-20240427-0712-rj6ui
labels:
owner: xds-k8s-interop-test
annotations:
cloud.google.com/neg: '{"exposed_ports": {"8080":{"name":"psm-interop-server-20240427-0712-rj6ui-psm-grpc-server"}}}'
spec:
type: ClusterIP
selector:
app: psm-grpc-server
ports:
- port: 8080
protocol: TCP
targetPort: 8080
...
I0427 07:13:18.695497 135711971115008 k8s_base_runner.py:367] Service psm-grpc-server created
I0427 07:13:18.695685 135711971115008 k8s_base_runner.py:1054] Waiting for 'cloud.google.com/neg-status' annotation for a NEG at port 8080 to be assigned to Kubernetes Service psm-grpc-server in namespace psm-interop-server-20240427-0712-rj6ui
I0427 07:13:18.784749 135711971115008 k8s_base_runner.py:1068] Detected 'cloud.google.com/neg-status' annotation for Kubernetes Service psm-grpc-server, namespace psm-interop-server-20240427-0712-rj6ui: neg_name=psm-interop-server-20240427-0712-rj6ui-psm-grpc-server, port=8080, zones=['us-central1-a']
I0427 07:13:18.784943 135711971115008 k8s_base_runner.py:452] Granting roles/iam.workloadIdentityUser to serviceAccount:grpc-testing.svc.id.goog[psm-interop-server-20240427-0712-rj6ui/psm-grpc-server] for GCP Service Account xds-k8s-interop-tests@grpc-testing.iam.gserviceaccount.com
I0427 07:13:19.477296 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/service-account.yaml:
---
apiVersion: v1
kind: ServiceAccount
metadata:
name: psm-grpc-server
namespace: psm-interop-server-20240427-0712-rj6ui
labels:
owner: xds-k8s-interop-test
annotations:
iam.gke.io/gcp-service-account: xds-k8s-interop-tests@grpc-testing.iam.gserviceaccount.com
...
I0427 07:13:19.532310 135711971115008 k8s_base_runner.py:367] ServiceAccount psm-grpc-server created
I0427 07:13:19.543903 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/server.deployment.yaml:
---
apiVersion: apps/v1
kind: Deployment
metadata:
name: psm-grpc-server
namespace: psm-interop-server-20240427-0712-rj6ui
labels:
app: psm-grpc-server
deployment_id: psm-grpc-server-vw6qlnhw
owner: xds-k8s-interop-test
spec:
replicas: 8
selector:
matchLabels:
app: psm-grpc-server
deployment_id: psm-grpc-server-vw6qlnhw
template:
metadata:
labels:
app: psm-grpc-server
deployment_id: psm-grpc-server-vw6qlnhw
owner: xds-k8s-interop-test
spec:
serviceAccountName: psm-grpc-server
containers:
- name: psm-grpc-server
image: us-docker.pkg.dev/grpc-testing/psm-interop/java-server:canonical
imagePullPolicy: Always
startupProbe:
tcpSocket:
port: 8080
periodSeconds: 3
failureThreshold: 1000
args:
- "--port=8080"
ports:
- containerPort: 8080
env:
- name: GRPC_XDS_BOOTSTRAP
value: "/tmp/grpc-xds/td-grpc-bootstrap.json"
- name: GRPC_XDS_EXPERIMENTAL_V3_SUPPORT
value: "true"
- name: GRPC_EXPERIMENTAL_XDS_ENABLE_OVERRIDE_HOST
value: "true"
volumeMounts:
- mountPath: /tmp/grpc-xds/
name: grpc-td-conf
readOnly: true
resources:
limits:
cpu: 800m
memory: 512Mi
requests:
cpu: 100m
memory: 512Mi
initContainers:
- name: grpc-td-init
image: us-docker.pkg.dev/grpc-testing/trafficdirector/td-grpc-bootstrap:2bf1b5ed00f852ffea8d24759c6fa673acc9ef10
imagePullPolicy: Always
args:
- "--output=/tmp/bootstrap/td-grpc-bootstrap.json"
- "--vpc-network-name=default-vpc"
- "--node-metadata=app=psm-interop-server-20240427-0712-rj6ui-psm-grpc-server"
resources:
limits:
cpu: 100m
memory: 100Mi
requests:
cpu: 10m
memory: 100Mi
volumeMounts:
- mountPath: /tmp/bootstrap/
name: grpc-td-conf
volumes:
- name: grpc-td-conf
emptyDir:
medium: Memory
...
I0427 07:13:19.612391 135711971115008 k8s_base_runner.py:367] Deployment psm-grpc-server created
I0427 07:13:19.612597 135711971115008 k8s_base_runner.py:962] Waiting for deployment psm-grpc-server to initialize 8 pod(s)
I0427 07:13:20.891690 135711971115008 k8s_base_runner.py:972] Deployment psm-grpc-server initialized 8 pod(s): ['psm-grpc-server-5645595cf5-26mck', 'psm-grpc-server-5645595cf5-2tnqr', 'psm-grpc-server-5645595cf5-9sjpf', 'psm-grpc-server-5645595cf5-dqtbq', 'psm-grpc-server-5645595cf5-jwthf', 'psm-grpc-server-5645595cf5-nls8h', 'psm-grpc-server-5645595cf5-q6bwx', 'psm-grpc-server-5645595cf5-wzjvr']
I0427 07:13:20.892333 135711971115008 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-5645595cf5-26mck to start
I0427 07:13:22.042404 135711971115008 k8s_base_runner.py:985] Pod psm-grpc-server-5645595cf5-26mck ready, IP: 10.120.11.234
I0427 07:13:22.042722 135711971115008 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-5645595cf5-26mck to subsetting_test/test_app_logs/psm-interop-server-20240427-0712-rj6ui_psm-grpc-server-5645595cf5-26mck.log
I0427 07:13:22.043246 135711872771648 k8s_log_collector.py:71] [ns/psm-interop-server-20240427-0712-rj6ui] Starting log collection thread 135711872771648 for psm-grpc-server-5645595cf5-26mck
I0427 07:13:22.043536 135711971115008 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-5645595cf5-2tnqr to start
I0427 07:13:24.222527 135711971115008 k8s_base_runner.py:985] Pod psm-grpc-server-5645595cf5-2tnqr ready, IP: 10.120.13.202
I0427 07:13:24.222750 135711971115008 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-5645595cf5-2tnqr to subsetting_test/test_app_logs/psm-interop-server-20240427-0712-rj6ui_psm-grpc-server-5645595cf5-2tnqr.log
I0427 07:13:24.223282 135711864378944 k8s_log_collector.py:71] [ns/psm-interop-server-20240427-0712-rj6ui] Starting log collection thread 135711864378944 for psm-grpc-server-5645595cf5-2tnqr
I0427 07:13:24.223498 135711971115008 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-5645595cf5-9sjpf to start
I0427 07:13:24.391838 135711971115008 k8s_base_runner.py:985] Pod psm-grpc-server-5645595cf5-9sjpf ready, IP: 10.120.17.14
I0427 07:13:24.392080 135711971115008 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-5645595cf5-9sjpf to subsetting_test/test_app_logs/psm-interop-server-20240427-0712-rj6ui_psm-grpc-server-5645595cf5-9sjpf.log
I0427 07:13:24.392493 135711855986240 k8s_log_collector.py:71] [ns/psm-interop-server-20240427-0712-rj6ui] Starting log collection thread 135711855986240 for psm-grpc-server-5645595cf5-9sjpf
I0427 07:13:24.392601 135711971115008 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-5645595cf5-dqtbq to start
I0427 07:13:24.561692 135711971115008 k8s_base_runner.py:985] Pod psm-grpc-server-5645595cf5-dqtbq ready, IP: 10.120.10.90
I0427 07:13:24.561949 135711971115008 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-5645595cf5-dqtbq to subsetting_test/test_app_logs/psm-interop-server-20240427-0712-rj6ui_psm-grpc-server-5645595cf5-dqtbq.log
I0427 07:13:24.562422 135711638419008 k8s_log_collector.py:71] [ns/psm-interop-server-20240427-0712-rj6ui] Starting log collection thread 135711638419008 for psm-grpc-server-5645595cf5-dqtbq
I0427 07:13:24.562741 135711971115008 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-5645595cf5-jwthf to start
I0427 07:13:24.731663 135711971115008 k8s_base_runner.py:985] Pod psm-grpc-server-5645595cf5-jwthf ready, IP: 10.120.16.123
I0427 07:13:24.731917 135711971115008 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-5645595cf5-jwthf to subsetting_test/test_app_logs/psm-interop-server-20240427-0712-rj6ui_psm-grpc-server-5645595cf5-jwthf.log
I0427 07:13:24.732530 135711630026304 k8s_log_collector.py:71] [ns/psm-interop-server-20240427-0712-rj6ui] Starting log collection thread 135711630026304 for psm-grpc-server-5645595cf5-jwthf
I0427 07:13:24.732752 135711971115008 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-5645595cf5-nls8h to start
I0427 07:13:24.896822 135711971115008 k8s_base_runner.py:985] Pod psm-grpc-server-5645595cf5-nls8h ready, IP: 10.120.9.2
I0427 07:13:24.897043 135711971115008 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-5645595cf5-nls8h to subsetting_test/test_app_logs/psm-interop-server-20240427-0712-rj6ui_psm-grpc-server-5645595cf5-nls8h.log
I0427 07:13:24.897508 135711621633600 k8s_log_collector.py:71] [ns/psm-interop-server-20240427-0712-rj6ui] Starting log collection thread 135711621633600 for psm-grpc-server-5645595cf5-nls8h
I0427 07:13:24.897705 135711971115008 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-5645595cf5-q6bwx to start
I0427 07:13:24.994227 135711971115008 k8s_base_runner.py:985] Pod psm-grpc-server-5645595cf5-q6bwx ready, IP: 10.120.14.152
I0427 07:13:24.994451 135711971115008 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-5645595cf5-q6bwx to subsetting_test/test_app_logs/psm-interop-server-20240427-0712-rj6ui_psm-grpc-server-5645595cf5-q6bwx.log
I0427 07:13:24.994958 135711613240896 k8s_log_collector.py:71] [ns/psm-interop-server-20240427-0712-rj6ui] Starting log collection thread 135711613240896 for psm-grpc-server-5645595cf5-q6bwx
I0427 07:13:24.995180 135711971115008 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-5645595cf5-wzjvr to start
I0427 07:13:25.164407 135711971115008 k8s_base_runner.py:985] Pod psm-grpc-server-5645595cf5-wzjvr ready, IP: 10.120.15.249
I0427 07:13:25.164664 135711971115008 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-5645595cf5-wzjvr to subsetting_test/test_app_logs/psm-interop-server-20240427-0712-rj6ui_psm-grpc-server-5645595cf5-wzjvr.log
I0427 07:13:25.165182 135711604848192 k8s_log_collector.py:71] [ns/psm-interop-server-20240427-0712-rj6ui] Starting log collection thread 135711604848192 for psm-grpc-server-5645595cf5-wzjvr
I0427 07:13:25.165413 135711971115008 k8s_base_runner.py:944] Waiting for deployment psm-grpc-server to report 8 available replica(s)
I0427 07:13:28.462875 135711971115008 k8s_base_runner.py:953] Deployment psm-grpc-server has 8 replicas available
I0427 07:13:28.463171 135711971115008 xds_k8s_testcase.py:304] --- Finished subTest SubsettingTest.test_subsetting_basic.05_start_test_servers ---
I0427 07:13:28.463285 135711971115008 xds_k8s_testcase.py:299] --- Starting subTest SubsettingTest.test_subsetting_basic.06_add_server_backends_to_backend_services ---
I0427 07:13:28.498936 135711971115008 traffic_director.py:256] Waiting for Network Endpoint Groups to load endpoints.
I0427 07:13:28.777637 135711971115008 traffic_director.py:259] Loaded NEG "psm-interop-server-20240427-0712-rj6ui-psm-grpc-server" in zone us-central1-a
I0427 07:13:28.777905 135711971115008 traffic_director.py:277] Adding backends to Backend Service psm-interop-backend-service-20240427-0712-rj6ui: {ComputeV1.ZonalGcpResource(name='psm-interop-server-20240427-0712-rj6ui-psm-grpc-server', url='https://www.googleapis.com/compute/alpha/projects/grpc-testing/zones/us-central1-a/networkEndpointGroups/psm-interop-server-20240427-0712-rj6ui-psm-grpc-server', zone='us-central1-a')}
I0427 07:13:28.781763 135711971115008 compute.py:544] Patching compute resource:
---
backends:
- balancingMode: RATE
group: https://www.googleapis.com/compute/alpha/projects/grpc-testing/zones/us-central1-a/networkEndpointGroups/psm-interop-server-20240427-0712-rj6ui-psm-grpc-server
maxRatePerEndpoint: 5
...
I0427 07:13:30.507197 135711971115008 compute.py:614] Waiting 600 sec for compute operation id: operation-1714202008783-6170ec1ce8afa-066c66ba-832723e2
I0427 07:14:04.736585 135711971115008 traffic_director.py:294] Waiting for Backend Service psm-interop-backend-service-20240427-0712-rj6ui to report all backends healthy: ['psm-interop-server-20240427-0712-rj6ui-psm-grpc-server']
I0427 07:14:17.634047 135711971115008 compute.py:494] Backend psm-interop-server-20240427-0712-rj6ui-psm-grpc-server in zone us-central1-a reported healthy
I0427 07:14:21.638650 135711971115008 xds_k8s_testcase.py:304] --- Finished subTest SubsettingTest.test_subsetting_basic.06_add_server_backends_to_backend_services ---
I0427 07:14:21.638917 135711971115008 xds_k8s_testcase.py:299] --- Starting subTest SubsettingTest.test_subsetting_basic.07_start_test_client ---
I0427 07:14:21.639046 135711971115008 k8s_xds_client_runner.py:119] Deploying xDS test client "psm-grpc-client" to k8s namespace psm-interop-client-20240427-0712-rj6ui: server_target=xds:///psm-grpc-server:13901 rpc=UnaryCall qps=25 metadata='' secure_mode=False print_response=False
I0427 07:14:21.639263 135711971115008 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-client:
https://console.cloud.google.com/logs/query;query=resource.type%3D%22k8s_container%22%0Aresource.labels.project_id%3D%22grpc-testing%22%0Aresource.labels.container_name%3D%22psm-grpc-client%22%0Aresource.labels.namespace_name%3D%22psm-interop-client-20240427-0712-rj6ui%22;timeRange=2024-04-27T07:14:21.639149Z%2F2024-04-27T07:44:21.639149Z?project=grpc-testing
I0427 07:14:21.640917 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/namespace.yaml:
---
apiVersion: v1
kind: Namespace
metadata:
name: psm-interop-client-20240427-0712-rj6ui
labels:
name: psm-interop-client-20240427-0712-rj6ui
owner: xds-k8s-interop-test
...
I0427 07:14:21.681769 135711971115008 k8s_base_runner.py:367] Namespace psm-interop-client-20240427-0712-rj6ui created
I0427 07:14:21.681997 135711971115008 k8s_base_runner.py:452] Granting roles/iam.workloadIdentityUser to serviceAccount:grpc-testing.svc.id.goog[psm-interop-client-20240427-0712-rj6ui/psm-grpc-client] for GCP Service Account xds-k8s-interop-tests@grpc-testing.iam.gserviceaccount.com
I0427 07:14:22.358804 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/service-account.yaml:
---
apiVersion: v1
kind: ServiceAccount
metadata:
name: psm-grpc-client
namespace: psm-interop-client-20240427-0712-rj6ui
labels:
owner: xds-k8s-interop-test
annotations:
iam.gke.io/gcp-service-account: xds-k8s-interop-tests@grpc-testing.iam.gserviceaccount.com
...
I0427 07:14:22.412751 135711971115008 k8s_base_runner.py:367] ServiceAccount psm-grpc-client created
I0427 07:14:22.420782 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/client.deployment.yaml:
---
apiVersion: apps/v1
kind: Deployment
metadata:
name: psm-grpc-client
namespace: psm-interop-client-20240427-0712-rj6ui
labels:
app: psm-grpc-client
deployment_id: psm-grpc-client-58edkzy0
owner: xds-k8s-interop-test
spec:
replicas: 1
selector:
matchLabels:
app: psm-grpc-client
deployment_id: psm-grpc-client-58edkzy0
template:
metadata:
labels:
app: psm-grpc-client
deployment_id: psm-grpc-client-58edkzy0
owner: xds-k8s-interop-test
spec:
serviceAccountName: psm-grpc-client
containers:
- name: psm-grpc-client
image: us-docker.pkg.dev/grpc-testing/psm-interop/node-client:c6391f3db078215cdfa8fdab35c5bbc2785f7956
imagePullPolicy: Always
startupProbe:
tcpSocket:
port: 8079
periodSeconds: 3
failureThreshold: 1000
args:
- "--server=xds:///psm-grpc-server:13901"
- "--stats_port=8079"
- "--qps=25"
- "--rpc=UnaryCall"
- "--metadata="
- "--print_response=False"
ports:
- containerPort: 8079
env:
- name: GRPC_XDS_BOOTSTRAP
value: "/tmp/grpc-xds/td-grpc-bootstrap.json"
- name: GRPC_XDS_EXPERIMENTAL_ENABLE_RING_HASH
value: "true"
- name: GRPC_XDS_EXPERIMENTAL_ENABLE_RETRY
value: "true"
- name: GRPC_EXPERIMENTAL_ENABLE_OUTLIER_DETECTION
value: "true"
- name: GRPC_EXPERIMENTAL_XDS_CUSTOM_LB_CONFIG
value: "true"
- name: GRPC_EXPERIMENTAL_XDS_ENABLE_OVERRIDE_HOST
value: "true"
volumeMounts:
- mountPath: /tmp/grpc-xds/
name: grpc-td-conf
readOnly: true
resources:
limits:
cpu: 800m
memory: 512Mi
requests:
cpu: 100m
memory: 512Mi
initContainers:
- name: grpc-td-init
image: us-docker.pkg.dev/grpc-testing/trafficdirector/td-grpc-bootstrap:2bf1b5ed00f852ffea8d24759c6fa673acc9ef10
imagePullPolicy: Always
args:
- "--output=/tmp/bootstrap/td-grpc-bootstrap.json"
- "--vpc-network-name=default-vpc"
resources:
limits:
cpu: 100m
memory: 100Mi
requests:
cpu: 10m
memory: 100Mi
volumeMounts:
- mountPath: /tmp/bootstrap/
name: grpc-td-conf
volumes:
- name: grpc-td-conf
emptyDir:
medium: Memory
...
I0427 07:14:22.486174 135711971115008 k8s_base_runner.py:367] Deployment psm-grpc-client created
I0427 07:14:22.486381 135711971115008 k8s_base_runner.py:962] Waiting for deployment psm-grpc-client to initialize 1 pod(s)
I0427 07:14:22.589309 135711971115008 k8s_base_runner.py:972] Deployment psm-grpc-client initialized 1 pod(s): ['psm-grpc-client-57cf98c859-cpqtj']
I0427 07:14:22.589546 135711971115008 k8s_base_runner.py:982] Waiting for pod psm-grpc-client-57cf98c859-cpqtj to start
I0427 07:14:25.812289 135711971115008 k8s_base_runner.py:985] Pod psm-grpc-client-57cf98c859-cpqtj ready, IP: 10.120.14.153
I0427 07:14:25.812539 135711971115008 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-client-57cf98c859-cpqtj to subsetting_test/test_app_logs/psm-interop-client-20240427-0712-rj6ui_psm-grpc-client-57cf98c859-cpqtj.log
I0427 07:14:25.813050 135711596455488 k8s_log_collector.py:71] [ns/psm-interop-client-20240427-0712-rj6ui] Starting log collection thread 135711596455488 for psm-grpc-client-57cf98c859-cpqtj
I0427 07:14:25.813305 135711971115008 k8s_base_runner.py:944] Waiting for deployment psm-grpc-client to report 1 available replica(s)
I0427 07:14:29.116238 135711971115008 k8s_base_runner.py:953] Deployment psm-grpc-client has 1 replicas available
I0427 07:14:29.116671 135711971115008 client_app.py:292] [psm-grpc-client-57cf98c859-cpqtj] ADS: Waiting for active calls to xDS control plane to trafficdirector.googleapis.com:443
I0427 07:14:29.279983 135711971115008 client_app.py:320] [psm-grpc-client-57cf98c859-cpqtj] xDS control plane channel:
I0427 07:14:39.364166 135711971115008 client_app.py:320] [psm-grpc-client-57cf98c859-cpqtj] xDS control plane channel:
I0427 07:14:49.448335 135711971115008 client_app.py:320] [psm-grpc-client-57cf98c859-cpqtj] xDS control plane channel:
I0427 07:14:59.531689 135711971115008 client_app.py:320] [psm-grpc-client-57cf98c859-cpqtj] xDS control plane channel:
I0427 07:15:09.616685 135711971115008 client_app.py:320] [psm-grpc-client-57cf98c859-cpqtj] xDS control plane channel:
I0427 07:15:25.706299 135711971115008 client_app.py:320] [psm-grpc-client-57cf98c859-cpqtj] xDS control plane channel:
I0427 07:15:50.804054 135711971115008 client_app.py:320] [psm-grpc-client-57cf98c859-cpqtj] xDS control plane channel:
I0427 07:16:15.903923 135711971115008 client_app.py:320] [psm-grpc-client-57cf98c859-cpqtj] xDS control plane channel:
I0427 07:16:17.945178 135711971115008 client_app.py:331] [psm-grpc-client-57cf98c859-cpqtj] Detected active calls to xDS control plane trafficdirector.googleapis.com:443, channel:
I0427 07:16:17.945567 135711971115008 client_app.py:302] [psm-grpc-client-57cf98c859-cpqtj] ADS: Detected active calls to xDS control plane trafficdirector.googleapis.com:443
I0427 07:16:17.946015 135711971115008 client_app.py:252] [psm-grpc-client-57cf98c859-cpqtj] Waiting to report a READY channel to xds:///psm-grpc-server:13901
I0427 07:16:17.981209 135711971115008 client_app.py:379] [psm-grpc-client-57cf98c859-cpqtj] Server channel:
I0427 07:16:18.020232 135711971115008 client_app.py:392] [psm-grpc-client-57cf98c859-cpqtj] Found subchannel in state READY:
I0427 07:16:18.020670 135711971115008 client_app.py:263] [psm-grpc-client-57cf98c859-cpqtj] Channel to xds:///psm-grpc-server:13901 transitioned to state READY:
I0427 07:16:18.067456 135711971115008 subsetting_test.py:88] Client 0 received endpoints (len=4): ['10.120.14.152:8080', '10.120.16.123:8080', '10.120.10.90:8080', '10.120.15.249:8080']
I0427 07:16:18.067833 135711971115008 grpc.py:75] [psm-grpc-client-57cf98c859-cpqtj:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 200, 'timeoutSec': 1200}), wait_for_ready=True, timeout=1200)
I0427 07:16:26.159125 135711971115008 xds_k8s_testcase.py:669] [psm-grpc-client-57cf98c859-cpqtj] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-5645595cf5-wzjvr: 50
psm-grpc-server-5645595cf5-q6bwx: 50
psm-grpc-server-5645595cf5-jwthf: 50
psm-grpc-server-5645595cf5-dqtbq: 50
rpcs_by_method:
UnaryCall:
psm-grpc-server-5645595cf5-wzjvr: 50
psm-grpc-server-5645595cf5-q6bwx: 50
psm-grpc-server-5645595cf5-jwthf: 50
psm-grpc-server-5645595cf5-dqtbq: 50
I0427 07:16:26.159424 135711971115008 k8s_base_runner.py:873] Deleting deployment psm-grpc-client
I0427 07:17:06.624337 135711971115008 k8s_base_runner.py:888] Deployment psm-grpc-client deleted
I0427 07:17:06.624641 135711971115008 k8s_base_runner.py:471] Revoking roles/iam.workloadIdentityUser from serviceAccount:grpc-testing.svc.id.goog[psm-interop-client-20240427-0712-rj6ui/psm-grpc-client] for GCP Service Account xds-k8s-interop-tests@grpc-testing.iam.gserviceaccount.com
I0427 07:17:07.118207 135711971115008 k8s_base_runner.py:907] Deleting service account psm-grpc-client
I0427 07:17:07.232642 135711971115008 k8s_base_runner.py:921] Service account psm-grpc-client deleted
I0427 07:17:07.232876 135711971115008 k8s_base_runner.py:924] Deleting namespace psm-interop-client-20240427-0712-rj6ui
I0427 07:17:37.404955 135711971115008 k8s_base_runner.py:941] Namespace psm-interop-client-20240427-0712-rj6ui deleted
I0427 07:17:37.405195 135711971115008 k8s_xds_client_runner.py:119] Deploying xDS test client "psm-grpc-client" to k8s namespace psm-interop-client-20240427-0712-rj6ui: server_target=xds:///psm-grpc-server:13901 rpc=UnaryCall qps=25 metadata='' secure_mode=False print_response=False
I0427 07:17:37.405515 135711971115008 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-client:
https://console.cloud.google.com/logs/query;query=resource.type%3D%22k8s_container%22%0Aresource.labels.project_id%3D%22grpc-testing%22%0Aresource.labels.container_name%3D%22psm-grpc-client%22%0Aresource.labels.namespace_name%3D%22psm-interop-client-20240427-0712-rj6ui%22;timeRange=2024-04-27T07:17:37.405416Z%2F2024-04-27T07:47:37.405416Z?project=grpc-testing
I0427 07:17:37.406085 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/namespace.yaml:
---
apiVersion: v1
kind: Namespace
metadata:
name: psm-interop-client-20240427-0712-rj6ui
labels:
name: psm-interop-client-20240427-0712-rj6ui
owner: xds-k8s-interop-test
...
I0427 07:17:37.464409 135711971115008 k8s_base_runner.py:367] Namespace psm-interop-client-20240427-0712-rj6ui created
I0427 07:17:37.464656 135711971115008 k8s_base_runner.py:452] Granting roles/iam.workloadIdentityUser to serviceAccount:grpc-testing.svc.id.goog[psm-interop-client-20240427-0712-rj6ui/psm-grpc-client] for GCP Service Account xds-k8s-interop-tests@grpc-testing.iam.gserviceaccount.com
I0427 07:17:38.151519 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/service-account.yaml:
---
apiVersion: v1
kind: ServiceAccount
metadata:
name: psm-grpc-client
namespace: psm-interop-client-20240427-0712-rj6ui
labels:
owner: xds-k8s-interop-test
annotations:
iam.gke.io/gcp-service-account: xds-k8s-interop-tests@grpc-testing.iam.gserviceaccount.com
...
I0427 07:17:38.204823 135711971115008 k8s_base_runner.py:367] ServiceAccount psm-grpc-client created
I0427 07:17:38.207531 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/client.deployment.yaml:
---
apiVersion: apps/v1
kind: Deployment
metadata:
name: psm-grpc-client
namespace: psm-interop-client-20240427-0712-rj6ui
labels:
app: psm-grpc-client
deployment_id: psm-grpc-client-89dkpjyw
owner: xds-k8s-interop-test
spec:
replicas: 1
selector:
matchLabels:
app: psm-grpc-client
deployment_id: psm-grpc-client-89dkpjyw
template:
metadata:
labels:
app: psm-grpc-client
deployment_id: psm-grpc-client-89dkpjyw
owner: xds-k8s-interop-test
spec:
serviceAccountName: psm-grpc-client
containers:
- name: psm-grpc-client
image: us-docker.pkg.dev/grpc-testing/psm-interop/node-client:c6391f3db078215cdfa8fdab35c5bbc2785f7956
imagePullPolicy: Always
startupProbe:
tcpSocket:
port: 8079
periodSeconds: 3
failureThreshold: 1000
args:
- "--server=xds:///psm-grpc-server:13901"
- "--stats_port=8079"
- "--qps=25"
- "--rpc=UnaryCall"
- "--metadata="
- "--print_response=False"
ports:
- containerPort: 8079
env:
- name: GRPC_XDS_BOOTSTRAP
value: "/tmp/grpc-xds/td-grpc-bootstrap.json"
- name: GRPC_XDS_EXPERIMENTAL_ENABLE_RING_HASH
value: "true"
- name: GRPC_XDS_EXPERIMENTAL_ENABLE_RETRY
value: "true"
- name: GRPC_EXPERIMENTAL_ENABLE_OUTLIER_DETECTION
value: "true"
- name: GRPC_EXPERIMENTAL_XDS_CUSTOM_LB_CONFIG
value: "true"
- name: GRPC_EXPERIMENTAL_XDS_ENABLE_OVERRIDE_HOST
value: "true"
volumeMounts:
- mountPath: /tmp/grpc-xds/
name: grpc-td-conf
readOnly: true
resources:
limits:
cpu: 800m
memory: 512Mi
requests:
cpu: 100m
memory: 512Mi
initContainers:
- name: grpc-td-init
image: us-docker.pkg.dev/grpc-testing/trafficdirector/td-grpc-bootstrap:2bf1b5ed00f852ffea8d24759c6fa673acc9ef10
imagePullPolicy: Always
args:
- "--output=/tmp/bootstrap/td-grpc-bootstrap.json"
- "--vpc-network-name=default-vpc"
resources:
limits:
cpu: 100m
memory: 100Mi
requests:
cpu: 10m
memory: 100Mi
volumeMounts:
- mountPath: /tmp/bootstrap/
name: grpc-td-conf
volumes:
- name: grpc-td-conf
emptyDir:
medium: Memory
...
I0427 07:17:38.277174 135711971115008 k8s_base_runner.py:367] Deployment psm-grpc-client created
I0427 07:17:38.277390 135711971115008 k8s_base_runner.py:962] Waiting for deployment psm-grpc-client to initialize 1 pod(s)
I0427 07:17:38.381602 135711971115008 k8s_base_runner.py:972] Deployment psm-grpc-client initialized 1 pod(s): ['psm-grpc-client-6795ffc767-wmzzm']
I0427 07:17:38.381870 135711971115008 k8s_base_runner.py:982] Waiting for pod psm-grpc-client-6795ffc767-wmzzm to start
I0427 07:17:41.610053 135711971115008 k8s_base_runner.py:985] Pod psm-grpc-client-6795ffc767-wmzzm ready, IP: 10.120.11.235
I0427 07:17:41.610282 135711971115008 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-client-6795ffc767-wmzzm to subsetting_test/test_app_logs/psm-interop-client-20240427-0712-rj6ui_psm-grpc-client-6795ffc767-wmzzm.log
I0427 07:17:41.610669 135711596455488 k8s_log_collector.py:71] [ns/psm-interop-client-20240427-0712-rj6ui] Starting log collection thread 135711596455488 for psm-grpc-client-6795ffc767-wmzzm
I0427 07:17:41.611002 135711971115008 k8s_base_runner.py:944] Waiting for deployment psm-grpc-client to report 1 available replica(s)
I0427 07:17:42.735918 135711971115008 k8s_base_runner.py:953] Deployment psm-grpc-client has 1 replicas available
I0427 07:17:42.736333 135711971115008 client_app.py:292] [psm-grpc-client-6795ffc767-wmzzm] ADS: Waiting for active calls to xDS control plane to trafficdirector.googleapis.com:443
I0427 07:17:42.882215 135711971115008 client_app.py:320] [psm-grpc-client-6795ffc767-wmzzm] xDS control plane channel:
I0427 07:17:44.922092 135711971115008 client_app.py:331] [psm-grpc-client-6795ffc767-wmzzm] Detected active calls to xDS control plane trafficdirector.googleapis.com:443, channel:
I0427 07:17:44.922480 135711971115008 client_app.py:302] [psm-grpc-client-6795ffc767-wmzzm] ADS: Detected active calls to xDS control plane trafficdirector.googleapis.com:443
I0427 07:17:44.922851 135711971115008 client_app.py:252] [psm-grpc-client-6795ffc767-wmzzm] Waiting to report a READY channel to xds:///psm-grpc-server:13901
I0427 07:17:44.957397 135711971115008 client_app.py:379] [psm-grpc-client-6795ffc767-wmzzm] Server channel:
I0427 07:17:44.995946 135711971115008 client_app.py:392] [psm-grpc-client-6795ffc767-wmzzm] Found subchannel in state READY:
I0427 07:17:44.996335 135711971115008 client_app.py:263] [psm-grpc-client-6795ffc767-wmzzm] Channel to xds:///psm-grpc-server:13901 transitioned to state READY:
I0427 07:17:45.038861 135711971115008 subsetting_test.py:88] Client 1 received endpoints (len=4): ['10.120.10.90:8080', '10.120.9.2:8080', '10.120.17.14:8080', '10.120.16.123:8080']
I0427 07:17:45.039275 135711971115008 grpc.py:75] [psm-grpc-client-6795ffc767-wmzzm:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 200, 'timeoutSec': 1200}), wait_for_ready=True, timeout=1200)
I0427 07:17:53.153697 135711971115008 xds_k8s_testcase.py:669] [psm-grpc-client-6795ffc767-wmzzm] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-5645595cf5-nls8h: 50
psm-grpc-server-5645595cf5-9sjpf: 50
psm-grpc-server-5645595cf5-dqtbq: 50
psm-grpc-server-5645595cf5-jwthf: 50
rpcs_by_method:
UnaryCall:
psm-grpc-server-5645595cf5-nls8h: 50
psm-grpc-server-5645595cf5-9sjpf: 50
psm-grpc-server-5645595cf5-dqtbq: 50
psm-grpc-server-5645595cf5-jwthf: 50
I0427 07:17:53.154227 135711971115008 k8s_base_runner.py:873] Deleting deployment psm-grpc-client
I0427 07:18:33.467436 135711971115008 k8s_base_runner.py:888] Deployment psm-grpc-client deleted
I0427 07:18:33.467703 135711971115008 k8s_base_runner.py:471] Revoking roles/iam.workloadIdentityUser from serviceAccount:grpc-testing.svc.id.goog[psm-interop-client-20240427-0712-rj6ui/psm-grpc-client] for GCP Service Account xds-k8s-interop-tests@grpc-testing.iam.gserviceaccount.com
I0427 07:18:34.144841 135711971115008 k8s_base_runner.py:907] Deleting service account psm-grpc-client
I0427 07:18:34.261604 135711971115008 k8s_base_runner.py:921] Service account psm-grpc-client deleted
I0427 07:18:34.261855 135711971115008 k8s_base_runner.py:924] Deleting namespace psm-interop-client-20240427-0712-rj6ui
I0427 07:19:04.437314 135711971115008 k8s_base_runner.py:941] Namespace psm-interop-client-20240427-0712-rj6ui deleted
I0427 07:19:04.437577 135711971115008 k8s_xds_client_runner.py:119] Deploying xDS test client "psm-grpc-client" to k8s namespace psm-interop-client-20240427-0712-rj6ui: server_target=xds:///psm-grpc-server:13901 rpc=UnaryCall qps=25 metadata='' secure_mode=False print_response=False
I0427 07:19:04.437994 135711971115008 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-client:
https://console.cloud.google.com/logs/query;query=resource.type%3D%22k8s_container%22%0Aresource.labels.project_id%3D%22grpc-testing%22%0Aresource.labels.container_name%3D%22psm-grpc-client%22%0Aresource.labels.namespace_name%3D%22psm-interop-client-20240427-0712-rj6ui%22;timeRange=2024-04-27T07:19:04.437878Z%2F2024-04-27T07:49:04.437878Z?project=grpc-testing
I0427 07:19:04.438560 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/namespace.yaml:
---
apiVersion: v1
kind: Namespace
metadata:
name: psm-interop-client-20240427-0712-rj6ui
labels:
name: psm-interop-client-20240427-0712-rj6ui
owner: xds-k8s-interop-test
...
I0427 07:19:04.501684 135711971115008 k8s_base_runner.py:367] Namespace psm-interop-client-20240427-0712-rj6ui created
I0427 07:19:04.501906 135711971115008 k8s_base_runner.py:452] Granting roles/iam.workloadIdentityUser to serviceAccount:grpc-testing.svc.id.goog[psm-interop-client-20240427-0712-rj6ui/psm-grpc-client] for GCP Service Account xds-k8s-interop-tests@grpc-testing.iam.gserviceaccount.com
I0427 07:19:05.141950 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/service-account.yaml:
---
apiVersion: v1
kind: ServiceAccount
metadata:
name: psm-grpc-client
namespace: psm-interop-client-20240427-0712-rj6ui
labels:
owner: xds-k8s-interop-test
annotations:
iam.gke.io/gcp-service-account: xds-k8s-interop-tests@grpc-testing.iam.gserviceaccount.com
...
I0427 07:19:05.202900 135711971115008 k8s_base_runner.py:367] ServiceAccount psm-grpc-client created
I0427 07:19:05.205614 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/client.deployment.yaml:
---
apiVersion: apps/v1
kind: Deployment
metadata:
name: psm-grpc-client
namespace: psm-interop-client-20240427-0712-rj6ui
labels:
app: psm-grpc-client
deployment_id: psm-grpc-client-aulmcare
owner: xds-k8s-interop-test
spec:
replicas: 1
selector:
matchLabels:
app: psm-grpc-client
deployment_id: psm-grpc-client-aulmcare
template:
metadata:
labels:
app: psm-grpc-client
deployment_id: psm-grpc-client-aulmcare
owner: xds-k8s-interop-test
spec:
serviceAccountName: psm-grpc-client
containers:
- name: psm-grpc-client
image: us-docker.pkg.dev/grpc-testing/psm-interop/node-client:c6391f3db078215cdfa8fdab35c5bbc2785f7956
imagePullPolicy: Always
startupProbe:
tcpSocket:
port: 8079
periodSeconds: 3
failureThreshold: 1000
args:
- "--server=xds:///psm-grpc-server:13901"
- "--stats_port=8079"
- "--qps=25"
- "--rpc=UnaryCall"
- "--metadata="
- "--print_response=False"
ports:
- containerPort: 8079
env:
- name: GRPC_XDS_BOOTSTRAP
value: "/tmp/grpc-xds/td-grpc-bootstrap.json"
- name: GRPC_XDS_EXPERIMENTAL_ENABLE_RING_HASH
value: "true"
- name: GRPC_XDS_EXPERIMENTAL_ENABLE_RETRY
value: "true"
- name: GRPC_EXPERIMENTAL_ENABLE_OUTLIER_DETECTION
value: "true"
- name: GRPC_EXPERIMENTAL_XDS_CUSTOM_LB_CONFIG
value: "true"
- name: GRPC_EXPERIMENTAL_XDS_ENABLE_OVERRIDE_HOST
value: "true"
volumeMounts:
- mountPath: /tmp/grpc-xds/
name: grpc-td-conf
readOnly: true
resources:
limits:
cpu: 800m
memory: 512Mi
requests:
cpu: 100m
memory: 512Mi
initContainers:
- name: grpc-td-init
image: us-docker.pkg.dev/grpc-testing/trafficdirector/td-grpc-bootstrap:2bf1b5ed00f852ffea8d24759c6fa673acc9ef10
imagePullPolicy: Always
args:
- "--output=/tmp/bootstrap/td-grpc-bootstrap.json"
- "--vpc-network-name=default-vpc"
resources:
limits:
cpu: 100m
memory: 100Mi
requests:
cpu: 10m
memory: 100Mi
volumeMounts:
- mountPath: /tmp/bootstrap/
name: grpc-td-conf
volumes:
- name: grpc-td-conf
emptyDir:
medium: Memory
...
I0427 07:19:05.277259 135711971115008 k8s_base_runner.py:367] Deployment psm-grpc-client created
I0427 07:19:05.277511 135711971115008 k8s_base_runner.py:962] Waiting for deployment psm-grpc-client to initialize 1 pod(s)
I0427 07:19:05.386714 135711971115008 k8s_base_runner.py:972] Deployment psm-grpc-client initialized 1 pod(s): ['psm-grpc-client-d4f7bf8cf-v2ttg']
I0427 07:19:05.386956 135711971115008 k8s_base_runner.py:982] Waiting for pod psm-grpc-client-d4f7bf8cf-v2ttg to start
I0427 07:19:08.645175 135711971115008 k8s_base_runner.py:985] Pod psm-grpc-client-d4f7bf8cf-v2ttg ready, IP: 10.120.17.15
I0427 07:19:08.645421 135711971115008 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-client-d4f7bf8cf-v2ttg to subsetting_test/test_app_logs/psm-interop-client-20240427-0712-rj6ui_psm-grpc-client-d4f7bf8cf-v2ttg.log
I0427 07:19:08.645773 135711596455488 k8s_log_collector.py:71] [ns/psm-interop-client-20240427-0712-rj6ui] Starting log collection thread 135711596455488 for psm-grpc-client-d4f7bf8cf-v2ttg
I0427 07:19:08.645957 135711971115008 k8s_base_runner.py:944] Waiting for deployment psm-grpc-client to report 1 available replica(s)
I0427 07:19:11.873575 135711971115008 k8s_base_runner.py:953] Deployment psm-grpc-client has 1 replicas available
I0427 07:19:11.873977 135711971115008 client_app.py:292] [psm-grpc-client-d4f7bf8cf-v2ttg] ADS: Waiting for active calls to xDS control plane to trafficdirector.googleapis.com:443
I0427 07:19:12.031206 135711971115008 client_app.py:320] [psm-grpc-client-d4f7bf8cf-v2ttg] xDS control plane channel:
I0427 07:19:14.071814 135711971115008 client_app.py:331] [psm-grpc-client-d4f7bf8cf-v2ttg] Detected active calls to xDS control plane trafficdirector.googleapis.com:443, channel:
I0427 07:19:14.072170 135711971115008 client_app.py:302] [psm-grpc-client-d4f7bf8cf-v2ttg] ADS: Detected active calls to xDS control plane trafficdirector.googleapis.com:443
I0427 07:19:14.072402 135711971115008 client_app.py:252] [psm-grpc-client-d4f7bf8cf-v2ttg] Waiting to report a READY channel to xds:///psm-grpc-server:13901
I0427 07:19:14.108012 135711971115008 client_app.py:379] [psm-grpc-client-d4f7bf8cf-v2ttg] Server channel:
I0427 07:19:14.147293 135711971115008 client_app.py:392] [psm-grpc-client-d4f7bf8cf-v2ttg] Found subchannel in state READY:
I0427 07:19:14.147701 135711971115008 client_app.py:263] [psm-grpc-client-d4f7bf8cf-v2ttg] Channel to xds:///psm-grpc-server:13901 transitioned to state READY:
I0427 07:19:14.193772 135711971115008 subsetting_test.py:88] Client 2 received endpoints (len=4): ['10.120.17.14:8080', '10.120.14.152:8080', '10.120.16.123:8080', '10.120.15.249:8080']
I0427 07:19:14.194442 135711971115008 grpc.py:75] [psm-grpc-client-d4f7bf8cf-v2ttg:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 200, 'timeoutSec': 1200}), wait_for_ready=True, timeout=1200)
I0427 07:19:22.285094 135711971115008 xds_k8s_testcase.py:669] [psm-grpc-client-d4f7bf8cf-v2ttg] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-5645595cf5-wzjvr: 50
psm-grpc-server-5645595cf5-q6bwx: 50
psm-grpc-server-5645595cf5-jwthf: 50
psm-grpc-server-5645595cf5-9sjpf: 50
rpcs_by_method:
UnaryCall:
psm-grpc-server-5645595cf5-wzjvr: 50
psm-grpc-server-5645595cf5-q6bwx: 50
psm-grpc-server-5645595cf5-jwthf: 50
psm-grpc-server-5645595cf5-9sjpf: 50
I0427 07:19:22.285378 135711971115008 xds_k8s_testcase.py:304] --- Finished subTest SubsettingTest.test_subsetting_basic.07_start_test_client ---
I0427 07:19:22.285499 135711971115008 xds_k8s_testcase.py:299] --- Starting subTest SubsettingTest.test_subsetting_basic.08_log_rpc_distribution ---
I0427 07:19:22.285596 135711971115008 subsetting_test.py:115] RPC distribution (len=6): [('psm-grpc-server-5645595cf5-jwthf', 150), ('psm-grpc-server-5645595cf5-wzjvr', 100), ('psm-grpc-server-5645595cf5-q6bwx', 100), ('psm-grpc-server-5645595cf5-dqtbq', 100), ('psm-grpc-server-5645595cf5-9sjpf', 100), ('psm-grpc-server-5645595cf5-nls8h', 50)]
I0427 07:19:22.285673 135711971115008 subsetting_test.py:124] Peak=150 Mean=100.0 Peak-to-Mean-Ratio=1.50
I0427 07:19:22.285738 135711971115008 xds_k8s_testcase.py:304] --- Finished subTest SubsettingTest.test_subsetting_basic.08_log_rpc_distribution ---
I0427 07:19:22.285852 135711971115008 xds_k8s_testcase.py:755] ----- TestMethod SubsettingTest.test_subsetting_basic teardown -----
I0427 07:19:22.459660 135711971115008 traffic_director.py:674] Deleting Forwarding rule "psm-interop-forwarding-rule-20240427-0712-rj6ui"
I0427 07:19:23.345674 135711971115008 compute.py:614] Waiting 600 sec for compute operation id: operation-1714202362471-6170ed6e36573-ea6c4cf3-607112b0
I0427 07:19:36.318457 135711971115008 traffic_director.py:713] Deleting alternative Forwarding rule "psm-interop-forwarding-rule-alt-20240427-0712-rj6ui"
I0427 07:19:36.413086 135711971115008 traffic_director.py:605] Deleting HTTP Target proxy "psm-interop-target-proxy-20240427-0712-rj6ui"
I0427 07:19:36.950716 135711971115008 traffic_director.py:593] Deleting Target GRPC proxy "psm-interop-target-proxy-20240427-0712-rj6ui"
I0427 07:19:37.533079 135711971115008 compute.py:614] Waiting 600 sec for compute operation id: operation-1714202376953-6170ed7c05fc1-f0ae40e3-a122cd10
I0427 07:19:39.791202 135711971115008 traffic_director.py:633] Deleting alternative Target GRPC proxy "psm-interop-target-proxy-alt-20240427-0712-rj6ui"
I0427 07:19:40.050675 135711971115008 traffic_director.py:525] Deleting URL Map "psm-interop-url-map-20240427-0712-rj6ui"
I0427 07:19:40.808527 135711971115008 compute.py:614] Waiting 600 sec for compute operation id: operation-1714202380055-6170ed7efb39b-c25992ba-9c29369c
I0427 07:19:43.073206 135711971115008 traffic_director.py:561] Deleting alternative URL Map "psm-interop-url-map-alt-20240427-0712-rj6ui"
I0427 07:19:43.548755 135711971115008 traffic_director.py:243] Deleting Backend Service "psm-interop-backend-service-20240427-0712-rj6ui"
I0427 07:19:44.325100 135711971115008 compute.py:614] Waiting 600 sec for compute operation id: operation-1714202383553-6170ed82515bb-3cb46aad-a610961e
I0427 07:20:08.002175 135711971115008 traffic_director.py:332] Deleting Alternative Backend Service "psm-interop-backend-service-alt-20240427-0712-rj6ui"
I0427 07:20:08.303375 135711971115008 traffic_director.py:405] Deleting Affinity Backend Service "psm-interop-backend-service-affinity-20240427-0712-rj6ui"
I0427 07:20:08.640110 135711971115008 traffic_director.py:202] Deleting Health Check "psm-interop-health-check-20240427-0712-rj6ui"
I0427 07:20:09.321731 135711971115008 compute.py:614] Waiting 600 sec for compute operation id: operation-1714202408723-6170ed9a52264-79489bc5-7821c01b
I0427 07:20:13.703743 135711971115008 k8s_base_runner.py:873] Deleting deployment psm-grpc-client
I0427 07:20:54.131837 135711971115008 k8s_base_runner.py:888] Deployment psm-grpc-client deleted
I0427 07:20:54.132191 135711971115008 k8s_base_runner.py:471] Revoking roles/iam.workloadIdentityUser from serviceAccount:grpc-testing.svc.id.goog[psm-interop-client-20240427-0712-rj6ui/psm-grpc-client] for GCP Service Account xds-k8s-interop-tests@grpc-testing.iam.gserviceaccount.com
I0427 07:20:54.740937 135711971115008 k8s_base_runner.py:907] Deleting service account psm-grpc-client
I0427 07:20:54.856319 135711971115008 k8s_base_runner.py:921] Service account psm-grpc-client deleted
I0427 07:20:54.856557 135711971115008 k8s_base_runner.py:924] Deleting namespace psm-interop-client-20240427-0712-rj6ui
I0427 07:21:25.059130 135711971115008 k8s_base_runner.py:941] Namespace psm-interop-client-20240427-0712-rj6ui deleted
I0427 07:21:25.059416 135711971115008 k8s_base_runner.py:873] Deleting deployment psm-grpc-server
I0427 07:21:35.328924 135711971115008 k8s_base_runner.py:888] Deployment psm-grpc-server deleted
I0427 07:21:35.329221 135711971115008 k8s_base_runner.py:891] Deleting service psm-grpc-server
I0427 07:21:35.447165 135711971115008 k8s_base_runner.py:904] Service psm-grpc-server deleted
I0427 07:21:35.447399 135711971115008 k8s_base_runner.py:471] Revoking roles/iam.workloadIdentityUser from serviceAccount:grpc-testing.svc.id.goog[psm-interop-server-20240427-0712-rj6ui/psm-grpc-server] for GCP Service Account xds-k8s-interop-tests@grpc-testing.iam.gserviceaccount.com
I0427 07:21:36.170972 135711971115008 k8s_base_runner.py:907] Deleting service account psm-grpc-server
I0427 07:21:36.298880 135711971115008 k8s_base_runner.py:921] Service account psm-grpc-server deleted
I0427 07:21:36.299114 135711971115008 k8s_base_runner.py:924] Deleting namespace psm-interop-server-20240427-0712-rj6ui
I0427 07:23:36.764007 135711971115008 k8s_base_runner.py:941] Namespace psm-interop-server-20240427-0712-rj6ui deleted
I0427 07:23:36.764413 135711971115008 xds_k8s_testcase.py:779] ----- Test client/server logs -----
I0427 07:23:36.764724 135711971115008 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-client-58edkzy0:
https://console.cloud.google.com/logs/query;query=resource.type%3D%22k8s_container%22%0Aresource.labels.project_id%3D%22grpc-testing%22%0Aresource.labels.container_name%3D%22psm-grpc-client%22%0Aresource.labels.namespace_name%3D%22psm-interop-client-20240427-0712-rj6ui%22%0Alabels.%22k8s-pod%2Fdeployment_id%22%3D%22psm-grpc-client-58edkzy0%22;timeRange=2024-04-27T07:14:21.639142Z%2F2024-04-27T07:17:37.405157Z;cursorTimestamp=2024-04-27T07:14:29.116446Z?project=grpc-testing
I0427 07:23:36.764937 135711971115008 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-client-89dkpjyw:
https://console.cloud.google.com/logs/query;query=resource.type%3D%22k8s_container%22%0Aresource.labels.project_id%3D%22grpc-testing%22%0Aresource.labels.container_name%3D%22psm-grpc-client%22%0Aresource.labels.namespace_name%3D%22psm-interop-client-20240427-0712-rj6ui%22%0Alabels.%22k8s-pod%2Fdeployment_id%22%3D%22psm-grpc-client-89dkpjyw%22;timeRange=2024-04-27T07:17:37.405409Z%2F2024-04-27T07:19:04.437532Z;cursorTimestamp=2024-04-27T07:17:42.736158Z?project=grpc-testing
I0427 07:23:36.765111 135711971115008 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-client-aulmcare:
https://console.cloud.google.com/logs/query;query=resource.type%3D%22k8s_container%22%0Aresource.labels.project_id%3D%22grpc-testing%22%0Aresource.labels.container_name%3D%22psm-grpc-client%22%0Aresource.labels.namespace_name%3D%22psm-interop-client-20240427-0712-rj6ui%22%0Alabels.%22k8s-pod%2Fdeployment_id%22%3D%22psm-grpc-client-aulmcare%22;timeRange=2024-04-27T07:19:04.437870Z%2F2024-04-27T07:21:25.059385Z;cursorTimestamp=2024-04-27T07:19:11.873795Z?project=grpc-testing
I0427 07:23:36.765261 135711971115008 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-server-vw6qlnhw:
https://console.cloud.google.com/logs/query;query=resource.type%3D%22k8s_container%22%0Aresource.labels.project_id%3D%22grpc-testing%22%0Aresource.labels.container_name%3D%22psm-grpc-server%22%0Aresource.labels.namespace_name%3D%22psm-interop-server-20240427-0712-rj6ui%22%0Alabels.%22k8s-pod%2Fdeployment_id%22%3D%22psm-grpc-server-vw6qlnhw%22;timeRange=2024-04-27T07:13:18.475596Z%2F2024-04-27T07:23:36.764243Z;cursorTimestamp=2024-04-27T07:13:28.463090Z?project=grpc-testing
[ OK ] SubsettingTest.test_subsetting_basic
I0427 07:23:36.765510 135711971115008 base_testcase.py:67] ----- PSM Test Case PASSED: SubsettingTest.test_subsetting_basic -----
----------------------------------------------------------------------
Ran 1 test in 683.197s
OK
+ [07:23:37 UTC] Cmd finished: python
+ [07:12:12 UTC] Test driver flags for subsetting_test:
--flagfile=config/grpc-testing.cfg
--kube_context=gke_grpc-testing_us-central1-a_psm-interop-lb-primary
--force_cleanup
--collect_app_logs
--log_dir=/tmpfs/src/artifacts/grpc/node/master/xds_k8s_lb/subsetting_test
--xml_output_file=/tmpfs/src/artifacts/grpc/node/master/xds_k8s_lb/subsetting_test/sponge_log.xml
--testing_version=dev-master
--client_image=us-docker.pkg.dev/grpc-testing/psm-interop/node-client:c6391f3db078215cdfa8fdab35c5bbc2785f7956
--server_image=us-docker.pkg.dev/grpc-testing/psm-interop/java-server:canonical
--secondary_kube_context=gke_grpc-testing_us-west1-b_psm-interop-lb-secondary
+ [07:12:12 UTC] python -m tests.subsetting_test --flagfile=config/grpc-testing.cfg --kube_context=gke_grpc-testing_us-central1-a_psm-interop-lb-primary --force_cleanup --collect_app_logs --log_dir=/tmpfs/src/artifacts/grpc/node/master/xds_k8s_lb/subsetting_test --xml_output_file=/tmpfs/src/artifacts/grpc/node/master/xds_k8s_lb/subsetting_test/sponge_log.xml --testing_version=dev-master --client_image=us-docker.pkg.dev/grpc-testing/psm-interop/node-client:c6391f3db078215cdfa8fdab35c5bbc2785f7956 --server_image=us-docker.pkg.dev/grpc-testing/psm-interop/java-server:canonical --secondary_kube_context=gke_grpc-testing_us-west1-b_psm-interop-lb-secondary
Running tests under Python 3.10.12: /tmp/tmp.AHy4VRCzAB/psm-interop/venv/bin/python
I0427 07:12:13.571059 135711971115008 xds_k8s_testcase.py:162] ----- Testing SubsettingTest -----
I0427 07:12:13.571166 135711971115008 xds_k8s_testcase.py:163] Logs timezone: UTC
I0427 07:12:13.571338 135711971115008 xds_k8s_testcase.py:111] Detected language and version: TestConfig(client_lang='node', server_lang='java', version='dev-master')
I0427 07:12:13.584826 135711971115008 k8s.py:243] Using kubernetes context "gke_grpc-testing_us-central1-a_psm-interop-lb-primary", active host: https://35.238.98.54
I0427 07:12:13.598238 135711971115008 k8s.py:243] Using kubernetes context "gke_grpc-testing_us-west1-b_psm-interop-lb-secondary", active host: https://35.227.140.120
[ RUN ] SubsettingTest.test_subsetting_basic
I0427 07:12:13.602038 135711971115008 xds_k8s_testcase.py:736] Test run resource prefix: psm-interop, suffix: 20240427-0712-rj6ui
I0427 07:12:13.883687 135711971115008 logs.py:31] Log root dir: /tmpfs/src/artifacts/grpc/node/master/xds_k8s_lb/subsetting_test
I0427 07:12:14.152826 135711971115008 xds_k8s_testcase.py:731] Found unused xds port: 13901
I0427 07:12:14.153234 135711971115008 xds_k8s_testcase.py:299] --- Starting subTest SubsettingTest.test_subsetting_basic.00_create_health_check ---
I0427 07:12:14.153356 135711971115008 traffic_director.py:191] Creating GRPC Health Check "psm-interop-health-check-20240427-0712-rj6ui"
I0427 07:12:14.156188 135711971115008 compute.py:537] Creating compute resource:
---
grpcHealthCheck:
portSpecification: USE_SERVING_PORT
name: psm-interop-health-check-20240427-0712-rj6ui
type: GRPC
...
I0427 07:12:14.946844 135711971115008 compute.py:614] Waiting 600 sec for compute operation id: operation-1714201934204-6170ebd5c8ebe-b1afdcf1-6797fab8
I0427 07:12:17.209044 135711971115008 xds_k8s_testcase.py:304] --- Finished subTest SubsettingTest.test_subsetting_basic.00_create_health_check ---
I0427 07:12:17.209241 135711971115008 xds_k8s_testcase.py:299] --- Starting subTest SubsettingTest.test_subsetting_basic.01_create_backend_services ---
I0427 07:12:17.209334 135711971115008 traffic_director.py:218] Creating GRPC Backend Service "psm-interop-backend-service-20240427-0712-rj6ui"
I0427 07:12:17.217066 135711971115008 compute.py:537] Creating compute resource:
---
healthChecks:
- https://www.googleapis.com/compute/alpha/projects/grpc-testing/global/healthChecks/psm-interop-health-check-20240427-0712-rj6ui
loadBalancingScheme: INTERNAL_SELF_MANAGED
name: psm-interop-backend-service-20240427-0712-rj6ui
protocol: GRPC
subsetting:
policy: CONSISTENT_HASH_SUBSETTING
subsetSize: 4
...
I0427 07:12:17.994876 135711971115008 compute.py:614] Waiting 600 sec for compute operation id: operation-1714201937219-6170ebd8a8e76-5183059f-b532de17
I0427 07:12:39.695245 135711971115008 xds_k8s_testcase.py:304] --- Finished subTest SubsettingTest.test_subsetting_basic.01_create_backend_services ---
I0427 07:12:39.695469 135711971115008 xds_k8s_testcase.py:299] --- Starting subTest SubsettingTest.test_subsetting_basic.02_create_url_map ---
I0427 07:12:39.695578 135711971115008 traffic_director.py:479] Creating URL map "psm-interop-url-map-20240427-0712-rj6ui": psm-grpc-server:13901 -> psm-interop-backend-service-20240427-0712-rj6ui
I0427 07:12:39.703910 135711971115008 compute.py:537] Creating compute resource:
---
defaultService: https://www.googleapis.com/compute/alpha/projects/grpc-testing/global/backendServices/psm-interop-backend-service-20240427-0712-rj6ui
hostRules:
- hosts:
- psm-grpc-server:13901
pathMatcher: psm-interop-path-matcher-20240427-0712-rj6ui
name: psm-interop-url-map-20240427-0712-rj6ui
pathMatchers:
- defaultService: https://www.googleapis.com/compute/alpha/projects/grpc-testing/global/backendServices/psm-interop-backend-service-20240427-0712-rj6ui
name: psm-interop-path-matcher-20240427-0712-rj6ui
...
I0427 07:12:40.337866 135711971115008 compute.py:614] Waiting 600 sec for compute operation id: operation-1714201959706-6170ebee1adff-f8087a8a-f83c08db
I0427 07:12:42.583690 135711971115008 xds_k8s_testcase.py:304] --- Finished subTest SubsettingTest.test_subsetting_basic.02_create_url_map ---
I0427 07:12:42.583921 135711971115008 xds_k8s_testcase.py:299] --- Starting subTest SubsettingTest.test_subsetting_basic.03_create_target_proxy ---
I0427 07:12:42.584043 135711971115008 traffic_director.py:578] Creating target psm-interop-target-proxy-20240427-0712-rj6ui proxy "GRPC" to URL map psm-interop-url-map-20240427-0712-rj6ui
I0427 07:12:42.585787 135711971115008 compute.py:537] Creating compute resource:
---
name: psm-interop-target-proxy-20240427-0712-rj6ui
url_map: https://www.googleapis.com/compute/alpha/projects/grpc-testing/global/urlMaps/psm-interop-url-map-20240427-0712-rj6ui
validate_for_proxyless: true
...
I0427 07:12:43.181981 135711971115008 compute.py:614] Waiting 600 sec for compute operation id: operation-1714201962587-6170ebf0da6ec-7916465b-f9b02423
I0427 07:12:45.450025 135711971115008 xds_k8s_testcase.py:304] --- Finished subTest SubsettingTest.test_subsetting_basic.03_create_target_proxy ---
I0427 07:12:45.450232 135711971115008 xds_k8s_testcase.py:299] --- Starting subTest SubsettingTest.test_subsetting_basic.04_create_forwarding_rule ---
I0427 07:12:45.450354 135711971115008 traffic_director.py:654] Creating forwarding rule "psm-interop-forwarding-rule-20240427-0712-rj6ui" in network "default-vpc": 0.0.0.0:13901 -> https://www.googleapis.com/compute/alpha/projects/grpc-testing/global/targetGrpcProxies/psm-interop-target-proxy-20240427-0712-rj6ui
I0427 07:12:45.452343 135711971115008 compute.py:537] Creating compute resource:
---
IPAddress: 0.0.0.0
loadBalancingScheme: INTERNAL_SELF_MANAGED
name: psm-interop-forwarding-rule-20240427-0712-rj6ui
network: global/networks/default-vpc
portRange: 13901
target: https://www.googleapis.com/compute/alpha/projects/grpc-testing/global/targetGrpcProxies/psm-interop-target-proxy-20240427-0712-rj6ui
...
I0427 07:12:46.462087 135711971115008 compute.py:614] Waiting 600 sec for compute operation id: operation-1714201965454-6170ebf39649a-8c28889d-49ed5855
I0427 07:13:18.475205 135711971115008 xds_k8s_testcase.py:304] --- Finished subTest SubsettingTest.test_subsetting_basic.04_create_forwarding_rule ---
I0427 07:13:18.475407 135711971115008 xds_k8s_testcase.py:299] --- Starting subTest SubsettingTest.test_subsetting_basic.05_start_test_servers ---
I0427 07:13:18.475507 135711971115008 k8s_xds_server_runner.py:186] Deploying xDS test server "psm-grpc-server" to k8s namespace psm-interop-server-20240427-0712-rj6ui: test_port=8080 maintenance_port=8080 secure_mode=False replica_count=8
I0427 07:13:18.475727 135711971115008 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-server:
https://console.cloud.google.com/logs/query;query=resource.type%3D%22k8s_container%22%0Aresource.labels.project_id%3D%22grpc-testing%22%0Aresource.labels.container_name%3D%22psm-grpc-server%22%0Aresource.labels.namespace_name%3D%22psm-interop-server-20240427-0712-rj6ui%22;timeRange=2024-04-27T07:13:18.475602Z%2F2024-04-27T07:43:18.475602Z?project=grpc-testing
I0427 07:13:18.479727 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/namespace.yaml:
---
apiVersion: v1
kind: Namespace
metadata:
name: psm-interop-server-20240427-0712-rj6ui
labels:
name: psm-interop-server-20240427-0712-rj6ui
owner: xds-k8s-interop-test
...
I0427 07:13:18.626076 135711971115008 k8s_base_runner.py:367] Namespace psm-interop-server-20240427-0712-rj6ui created
I0427 07:13:18.628238 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/server.service.yaml:
---
apiVersion: v1
kind: Service
metadata:
name: psm-grpc-server
namespace: psm-interop-server-20240427-0712-rj6ui
labels:
owner: xds-k8s-interop-test
annotations:
cloud.google.com/neg: '{"exposed_ports": {"8080":{"name":"psm-interop-server-20240427-0712-rj6ui-psm-grpc-server"}}}'
spec:
type: ClusterIP
selector:
app: psm-grpc-server
ports:
- port: 8080
protocol: TCP
targetPort: 8080
...
I0427 07:13:18.695497 135711971115008 k8s_base_runner.py:367] Service psm-grpc-server created
I0427 07:13:18.695685 135711971115008 k8s_base_runner.py:1054] Waiting for 'cloud.google.com/neg-status' annotation for a NEG at port 8080 to be assigned to Kubernetes Service psm-grpc-server in namespace psm-interop-server-20240427-0712-rj6ui
I0427 07:13:18.784749 135711971115008 k8s_base_runner.py:1068] Detected 'cloud.google.com/neg-status' annotation for Kubernetes Service psm-grpc-server, namespace psm-interop-server-20240427-0712-rj6ui: neg_name=psm-interop-server-20240427-0712-rj6ui-psm-grpc-server, port=8080, zones=['us-central1-a']
I0427 07:13:18.784943 135711971115008 k8s_base_runner.py:452] Granting roles/iam.workloadIdentityUser to serviceAccount:grpc-testing.svc.id.goog[psm-interop-server-20240427-0712-rj6ui/psm-grpc-server] for GCP Service Account xds-k8s-interop-tests@grpc-testing.iam.gserviceaccount.com
I0427 07:13:19.477296 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/service-account.yaml:
---
apiVersion: v1
kind: ServiceAccount
metadata:
name: psm-grpc-server
namespace: psm-interop-server-20240427-0712-rj6ui
labels:
owner: xds-k8s-interop-test
annotations:
iam.gke.io/gcp-service-account: xds-k8s-interop-tests@grpc-testing.iam.gserviceaccount.com
...
I0427 07:13:19.532310 135711971115008 k8s_base_runner.py:367] ServiceAccount psm-grpc-server created
I0427 07:13:19.543903 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/server.deployment.yaml:
---
apiVersion: apps/v1
kind: Deployment
metadata:
name: psm-grpc-server
namespace: psm-interop-server-20240427-0712-rj6ui
labels:
app: psm-grpc-server
deployment_id: psm-grpc-server-vw6qlnhw
owner: xds-k8s-interop-test
spec:
replicas: 8
selector:
matchLabels:
app: psm-grpc-server
deployment_id: psm-grpc-server-vw6qlnhw
template:
metadata:
labels:
app: psm-grpc-server
deployment_id: psm-grpc-server-vw6qlnhw
owner: xds-k8s-interop-test
spec:
serviceAccountName: psm-grpc-server
containers:
- name: psm-grpc-server
image: us-docker.pkg.dev/grpc-testing/psm-interop/java-server:canonical
imagePullPolicy: Always
startupProbe:
tcpSocket:
port: 8080
periodSeconds: 3
failureThreshold: 1000
args:
- "--port=8080"
ports:
- containerPort: 8080
env:
- name: GRPC_XDS_BOOTSTRAP
value: "/tmp/grpc-xds/td-grpc-bootstrap.json"
- name: GRPC_XDS_EXPERIMENTAL_V3_SUPPORT
value: "true"
- name: GRPC_EXPERIMENTAL_XDS_ENABLE_OVERRIDE_HOST
value: "true"
volumeMounts:
- mountPath: /tmp/grpc-xds/
name: grpc-td-conf
readOnly: true
resources:
limits:
cpu: 800m
memory: 512Mi
requests:
cpu: 100m
memory: 512Mi
initContainers:
- name: grpc-td-init
image: us-docker.pkg.dev/grpc-testing/trafficdirector/td-grpc-bootstrap:2bf1b5ed00f852ffea8d24759c6fa673acc9ef10
imagePullPolicy: Always
args:
- "--output=/tmp/bootstrap/td-grpc-bootstrap.json"
- "--vpc-network-name=default-vpc"
- "--node-metadata=app=psm-interop-server-20240427-0712-rj6ui-psm-grpc-server"
resources:
limits:
cpu: 100m
memory: 100Mi
requests:
cpu: 10m
memory: 100Mi
volumeMounts:
- mountPath: /tmp/bootstrap/
name: grpc-td-conf
volumes:
- name: grpc-td-conf
emptyDir:
medium: Memory
...
I0427 07:13:19.612391 135711971115008 k8s_base_runner.py:367] Deployment psm-grpc-server created
I0427 07:13:19.612597 135711971115008 k8s_base_runner.py:962] Waiting for deployment psm-grpc-server to initialize 8 pod(s)
I0427 07:13:20.891690 135711971115008 k8s_base_runner.py:972] Deployment psm-grpc-server initialized 8 pod(s): ['psm-grpc-server-5645595cf5-26mck', 'psm-grpc-server-5645595cf5-2tnqr', 'psm-grpc-server-5645595cf5-9sjpf', 'psm-grpc-server-5645595cf5-dqtbq', 'psm-grpc-server-5645595cf5-jwthf', 'psm-grpc-server-5645595cf5-nls8h', 'psm-grpc-server-5645595cf5-q6bwx', 'psm-grpc-server-5645595cf5-wzjvr']
I0427 07:13:20.892333 135711971115008 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-5645595cf5-26mck to start
I0427 07:13:22.042404 135711971115008 k8s_base_runner.py:985] Pod psm-grpc-server-5645595cf5-26mck ready, IP: 10.120.11.234
I0427 07:13:22.042722 135711971115008 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-5645595cf5-26mck to subsetting_test/test_app_logs/psm-interop-server-20240427-0712-rj6ui_psm-grpc-server-5645595cf5-26mck.log
I0427 07:13:22.043246 135711872771648 k8s_log_collector.py:71] [ns/psm-interop-server-20240427-0712-rj6ui] Starting log collection thread 135711872771648 for psm-grpc-server-5645595cf5-26mck
I0427 07:13:22.043536 135711971115008 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-5645595cf5-2tnqr to start
I0427 07:13:24.222527 135711971115008 k8s_base_runner.py:985] Pod psm-grpc-server-5645595cf5-2tnqr ready, IP: 10.120.13.202
I0427 07:13:24.222750 135711971115008 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-5645595cf5-2tnqr to subsetting_test/test_app_logs/psm-interop-server-20240427-0712-rj6ui_psm-grpc-server-5645595cf5-2tnqr.log
I0427 07:13:24.223282 135711864378944 k8s_log_collector.py:71] [ns/psm-interop-server-20240427-0712-rj6ui] Starting log collection thread 135711864378944 for psm-grpc-server-5645595cf5-2tnqr
I0427 07:13:24.223498 135711971115008 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-5645595cf5-9sjpf to start
I0427 07:13:24.391838 135711971115008 k8s_base_runner.py:985] Pod psm-grpc-server-5645595cf5-9sjpf ready, IP: 10.120.17.14
I0427 07:13:24.392080 135711971115008 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-5645595cf5-9sjpf to subsetting_test/test_app_logs/psm-interop-server-20240427-0712-rj6ui_psm-grpc-server-5645595cf5-9sjpf.log
I0427 07:13:24.392493 135711855986240 k8s_log_collector.py:71] [ns/psm-interop-server-20240427-0712-rj6ui] Starting log collection thread 135711855986240 for psm-grpc-server-5645595cf5-9sjpf
I0427 07:13:24.392601 135711971115008 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-5645595cf5-dqtbq to start
I0427 07:13:24.561692 135711971115008 k8s_base_runner.py:985] Pod psm-grpc-server-5645595cf5-dqtbq ready, IP: 10.120.10.90
I0427 07:13:24.561949 135711971115008 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-5645595cf5-dqtbq to subsetting_test/test_app_logs/psm-interop-server-20240427-0712-rj6ui_psm-grpc-server-5645595cf5-dqtbq.log
I0427 07:13:24.562422 135711638419008 k8s_log_collector.py:71] [ns/psm-interop-server-20240427-0712-rj6ui] Starting log collection thread 135711638419008 for psm-grpc-server-5645595cf5-dqtbq
I0427 07:13:24.562741 135711971115008 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-5645595cf5-jwthf to start
I0427 07:13:24.731663 135711971115008 k8s_base_runner.py:985] Pod psm-grpc-server-5645595cf5-jwthf ready, IP: 10.120.16.123
I0427 07:13:24.731917 135711971115008 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-5645595cf5-jwthf to subsetting_test/test_app_logs/psm-interop-server-20240427-0712-rj6ui_psm-grpc-server-5645595cf5-jwthf.log
I0427 07:13:24.732530 135711630026304 k8s_log_collector.py:71] [ns/psm-interop-server-20240427-0712-rj6ui] Starting log collection thread 135711630026304 for psm-grpc-server-5645595cf5-jwthf
I0427 07:13:24.732752 135711971115008 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-5645595cf5-nls8h to start
I0427 07:13:24.896822 135711971115008 k8s_base_runner.py:985] Pod psm-grpc-server-5645595cf5-nls8h ready, IP: 10.120.9.2
I0427 07:13:24.897043 135711971115008 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-5645595cf5-nls8h to subsetting_test/test_app_logs/psm-interop-server-20240427-0712-rj6ui_psm-grpc-server-5645595cf5-nls8h.log
I0427 07:13:24.897508 135711621633600 k8s_log_collector.py:71] [ns/psm-interop-server-20240427-0712-rj6ui] Starting log collection thread 135711621633600 for psm-grpc-server-5645595cf5-nls8h
I0427 07:13:24.897705 135711971115008 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-5645595cf5-q6bwx to start
I0427 07:13:24.994227 135711971115008 k8s_base_runner.py:985] Pod psm-grpc-server-5645595cf5-q6bwx ready, IP: 10.120.14.152
I0427 07:13:24.994451 135711971115008 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-5645595cf5-q6bwx to subsetting_test/test_app_logs/psm-interop-server-20240427-0712-rj6ui_psm-grpc-server-5645595cf5-q6bwx.log
I0427 07:13:24.994958 135711613240896 k8s_log_collector.py:71] [ns/psm-interop-server-20240427-0712-rj6ui] Starting log collection thread 135711613240896 for psm-grpc-server-5645595cf5-q6bwx
I0427 07:13:24.995180 135711971115008 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-5645595cf5-wzjvr to start
I0427 07:13:25.164407 135711971115008 k8s_base_runner.py:985] Pod psm-grpc-server-5645595cf5-wzjvr ready, IP: 10.120.15.249
I0427 07:13:25.164664 135711971115008 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-5645595cf5-wzjvr to subsetting_test/test_app_logs/psm-interop-server-20240427-0712-rj6ui_psm-grpc-server-5645595cf5-wzjvr.log
I0427 07:13:25.165182 135711604848192 k8s_log_collector.py:71] [ns/psm-interop-server-20240427-0712-rj6ui] Starting log collection thread 135711604848192 for psm-grpc-server-5645595cf5-wzjvr
I0427 07:13:25.165413 135711971115008 k8s_base_runner.py:944] Waiting for deployment psm-grpc-server to report 8 available replica(s)
I0427 07:13:28.462875 135711971115008 k8s_base_runner.py:953] Deployment psm-grpc-server has 8 replicas available
I0427 07:13:28.463171 135711971115008 xds_k8s_testcase.py:304] --- Finished subTest SubsettingTest.test_subsetting_basic.05_start_test_servers ---
I0427 07:13:28.463285 135711971115008 xds_k8s_testcase.py:299] --- Starting subTest SubsettingTest.test_subsetting_basic.06_add_server_backends_to_backend_services ---
I0427 07:13:28.498936 135711971115008 traffic_director.py:256] Waiting for Network Endpoint Groups to load endpoints.
I0427 07:13:28.777637 135711971115008 traffic_director.py:259] Loaded NEG "psm-interop-server-20240427-0712-rj6ui-psm-grpc-server" in zone us-central1-a
I0427 07:13:28.777905 135711971115008 traffic_director.py:277] Adding backends to Backend Service psm-interop-backend-service-20240427-0712-rj6ui: {ComputeV1.ZonalGcpResource(name='psm-interop-server-20240427-0712-rj6ui-psm-grpc-server', url='https://www.googleapis.com/compute/alpha/projects/grpc-testing/zones/us-central1-a/networkEndpointGroups/psm-interop-server-20240427-0712-rj6ui-psm-grpc-server', zone='us-central1-a')}
I0427 07:13:28.781763 135711971115008 compute.py:544] Patching compute resource:
---
backends:
- balancingMode: RATE
group: https://www.googleapis.com/compute/alpha/projects/grpc-testing/zones/us-central1-a/networkEndpointGroups/psm-interop-server-20240427-0712-rj6ui-psm-grpc-server
maxRatePerEndpoint: 5
...
I0427 07:13:30.507197 135711971115008 compute.py:614] Waiting 600 sec for compute operation id: operation-1714202008783-6170ec1ce8afa-066c66ba-832723e2
I0427 07:14:04.736585 135711971115008 traffic_director.py:294] Waiting for Backend Service psm-interop-backend-service-20240427-0712-rj6ui to report all backends healthy: ['psm-interop-server-20240427-0712-rj6ui-psm-grpc-server']
I0427 07:14:17.634047 135711971115008 compute.py:494] Backend psm-interop-server-20240427-0712-rj6ui-psm-grpc-server in zone us-central1-a reported healthy
I0427 07:14:21.638650 135711971115008 xds_k8s_testcase.py:304] --- Finished subTest SubsettingTest.test_subsetting_basic.06_add_server_backends_to_backend_services ---
I0427 07:14:21.638917 135711971115008 xds_k8s_testcase.py:299] --- Starting subTest SubsettingTest.test_subsetting_basic.07_start_test_client ---
I0427 07:14:21.639046 135711971115008 k8s_xds_client_runner.py:119] Deploying xDS test client "psm-grpc-client" to k8s namespace psm-interop-client-20240427-0712-rj6ui: server_target=xds:///psm-grpc-server:13901 rpc=UnaryCall qps=25 metadata='' secure_mode=False print_response=False
I0427 07:14:21.639263 135711971115008 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-client:
https://console.cloud.google.com/logs/query;query=resource.type%3D%22k8s_container%22%0Aresource.labels.project_id%3D%22grpc-testing%22%0Aresource.labels.container_name%3D%22psm-grpc-client%22%0Aresource.labels.namespace_name%3D%22psm-interop-client-20240427-0712-rj6ui%22;timeRange=2024-04-27T07:14:21.639149Z%2F2024-04-27T07:44:21.639149Z?project=grpc-testing
I0427 07:14:21.640917 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/namespace.yaml:
---
apiVersion: v1
kind: Namespace
metadata:
name: psm-interop-client-20240427-0712-rj6ui
labels:
name: psm-interop-client-20240427-0712-rj6ui
owner: xds-k8s-interop-test
...
I0427 07:14:21.681769 135711971115008 k8s_base_runner.py:367] Namespace psm-interop-client-20240427-0712-rj6ui created
I0427 07:14:21.681997 135711971115008 k8s_base_runner.py:452] Granting roles/iam.workloadIdentityUser to serviceAccount:grpc-testing.svc.id.goog[psm-interop-client-20240427-0712-rj6ui/psm-grpc-client] for GCP Service Account xds-k8s-interop-tests@grpc-testing.iam.gserviceaccount.com
I0427 07:14:22.358804 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/service-account.yaml:
---
apiVersion: v1
kind: ServiceAccount
metadata:
name: psm-grpc-client
namespace: psm-interop-client-20240427-0712-rj6ui
labels:
owner: xds-k8s-interop-test
annotations:
iam.gke.io/gcp-service-account: xds-k8s-interop-tests@grpc-testing.iam.gserviceaccount.com
...
I0427 07:14:22.412751 135711971115008 k8s_base_runner.py:367] ServiceAccount psm-grpc-client created
I0427 07:14:22.420782 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/client.deployment.yaml:
---
apiVersion: apps/v1
kind: Deployment
metadata:
name: psm-grpc-client
namespace: psm-interop-client-20240427-0712-rj6ui
labels:
app: psm-grpc-client
deployment_id: psm-grpc-client-58edkzy0
owner: xds-k8s-interop-test
spec:
replicas: 1
selector:
matchLabels:
app: psm-grpc-client
deployment_id: psm-grpc-client-58edkzy0
template:
metadata:
labels:
app: psm-grpc-client
deployment_id: psm-grpc-client-58edkzy0
owner: xds-k8s-interop-test
spec:
serviceAccountName: psm-grpc-client
containers:
- name: psm-grpc-client
image: us-docker.pkg.dev/grpc-testing/psm-interop/node-client:c6391f3db078215cdfa8fdab35c5bbc2785f7956
imagePullPolicy: Always
startupProbe:
tcpSocket:
port: 8079
periodSeconds: 3
failureThreshold: 1000
args:
- "--server=xds:///psm-grpc-server:13901"
- "--stats_port=8079"
- "--qps=25"
- "--rpc=UnaryCall"
- "--metadata="
- "--print_response=False"
ports:
- containerPort: 8079
env:
- name: GRPC_XDS_BOOTSTRAP
value: "/tmp/grpc-xds/td-grpc-bootstrap.json"
- name: GRPC_XDS_EXPERIMENTAL_ENABLE_RING_HASH
value: "true"
- name: GRPC_XDS_EXPERIMENTAL_ENABLE_RETRY
value: "true"
- name: GRPC_EXPERIMENTAL_ENABLE_OUTLIER_DETECTION
value: "true"
- name: GRPC_EXPERIMENTAL_XDS_CUSTOM_LB_CONFIG
value: "true"
- name: GRPC_EXPERIMENTAL_XDS_ENABLE_OVERRIDE_HOST
value: "true"
volumeMounts:
- mountPath: /tmp/grpc-xds/
name: grpc-td-conf
readOnly: true
resources:
limits:
cpu: 800m
memory: 512Mi
requests:
cpu: 100m
memory: 512Mi
initContainers:
- name: grpc-td-init
image: us-docker.pkg.dev/grpc-testing/trafficdirector/td-grpc-bootstrap:2bf1b5ed00f852ffea8d24759c6fa673acc9ef10
imagePullPolicy: Always
args:
- "--output=/tmp/bootstrap/td-grpc-bootstrap.json"
- "--vpc-network-name=default-vpc"
resources:
limits:
cpu: 100m
memory: 100Mi
requests:
cpu: 10m
memory: 100Mi
volumeMounts:
- mountPath: /tmp/bootstrap/
name: grpc-td-conf
volumes:
- name: grpc-td-conf
emptyDir:
medium: Memory
...
I0427 07:14:22.486174 135711971115008 k8s_base_runner.py:367] Deployment psm-grpc-client created
I0427 07:14:22.486381 135711971115008 k8s_base_runner.py:962] Waiting for deployment psm-grpc-client to initialize 1 pod(s)
I0427 07:14:22.589309 135711971115008 k8s_base_runner.py:972] Deployment psm-grpc-client initialized 1 pod(s): ['psm-grpc-client-57cf98c859-cpqtj']
I0427 07:14:22.589546 135711971115008 k8s_base_runner.py:982] Waiting for pod psm-grpc-client-57cf98c859-cpqtj to start
I0427 07:14:25.812289 135711971115008 k8s_base_runner.py:985] Pod psm-grpc-client-57cf98c859-cpqtj ready, IP: 10.120.14.153
I0427 07:14:25.812539 135711971115008 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-client-57cf98c859-cpqtj to subsetting_test/test_app_logs/psm-interop-client-20240427-0712-rj6ui_psm-grpc-client-57cf98c859-cpqtj.log
I0427 07:14:25.813050 135711596455488 k8s_log_collector.py:71] [ns/psm-interop-client-20240427-0712-rj6ui] Starting log collection thread 135711596455488 for psm-grpc-client-57cf98c859-cpqtj
I0427 07:14:25.813305 135711971115008 k8s_base_runner.py:944] Waiting for deployment psm-grpc-client to report 1 available replica(s)
I0427 07:14:29.116238 135711971115008 k8s_base_runner.py:953] Deployment psm-grpc-client has 1 replicas available
I0427 07:14:29.116671 135711971115008 client_app.py:292] [psm-grpc-client-57cf98c859-cpqtj] ADS: Waiting for active calls to xDS control plane to trafficdirector.googleapis.com:443
I0427 07:14:29.279983 135711971115008 client_app.py:320] [psm-grpc-client-57cf98c859-cpqtj] xDS control plane channel:
I0427 07:14:39.364166 135711971115008 client_app.py:320] [psm-grpc-client-57cf98c859-cpqtj] xDS control plane channel:
I0427 07:14:49.448335 135711971115008 client_app.py:320] [psm-grpc-client-57cf98c859-cpqtj] xDS control plane channel:
I0427 07:14:59.531689 135711971115008 client_app.py:320] [psm-grpc-client-57cf98c859-cpqtj] xDS control plane channel:
I0427 07:15:09.616685 135711971115008 client_app.py:320] [psm-grpc-client-57cf98c859-cpqtj] xDS control plane channel:
I0427 07:15:25.706299 135711971115008 client_app.py:320] [psm-grpc-client-57cf98c859-cpqtj] xDS control plane channel:
I0427 07:15:50.804054 135711971115008 client_app.py:320] [psm-grpc-client-57cf98c859-cpqtj] xDS control plane channel:
I0427 07:16:15.903923 135711971115008 client_app.py:320] [psm-grpc-client-57cf98c859-cpqtj] xDS control plane channel:
I0427 07:16:17.945178 135711971115008 client_app.py:331] [psm-grpc-client-57cf98c859-cpqtj] Detected active calls to xDS control plane trafficdirector.googleapis.com:443, channel:
I0427 07:16:17.945567 135711971115008 client_app.py:302] [psm-grpc-client-57cf98c859-cpqtj] ADS: Detected active calls to xDS control plane trafficdirector.googleapis.com:443
I0427 07:16:17.946015 135711971115008 client_app.py:252] [psm-grpc-client-57cf98c859-cpqtj] Waiting to report a READY channel to xds:///psm-grpc-server:13901
I0427 07:16:17.981209 135711971115008 client_app.py:379] [psm-grpc-client-57cf98c859-cpqtj] Server channel:
I0427 07:16:18.020232 135711971115008 client_app.py:392] [psm-grpc-client-57cf98c859-cpqtj] Found subchannel in state READY:
I0427 07:16:18.020670 135711971115008 client_app.py:263] [psm-grpc-client-57cf98c859-cpqtj] Channel to xds:///psm-grpc-server:13901 transitioned to state READY:
I0427 07:16:18.067456 135711971115008 subsetting_test.py:88] Client 0 received endpoints (len=4): ['10.120.14.152:8080', '10.120.16.123:8080', '10.120.10.90:8080', '10.120.15.249:8080']
I0427 07:16:18.067833 135711971115008 grpc.py:75] [psm-grpc-client-57cf98c859-cpqtj:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 200, 'timeoutSec': 1200}), wait_for_ready=True, timeout=1200)
I0427 07:16:26.159125 135711971115008 xds_k8s_testcase.py:669] [psm-grpc-client-57cf98c859-cpqtj] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-5645595cf5-wzjvr: 50
psm-grpc-server-5645595cf5-q6bwx: 50
psm-grpc-server-5645595cf5-jwthf: 50
psm-grpc-server-5645595cf5-dqtbq: 50
rpcs_by_method:
UnaryCall:
psm-grpc-server-5645595cf5-wzjvr: 50
psm-grpc-server-5645595cf5-q6bwx: 50
psm-grpc-server-5645595cf5-jwthf: 50
psm-grpc-server-5645595cf5-dqtbq: 50
I0427 07:16:26.159424 135711971115008 k8s_base_runner.py:873] Deleting deployment psm-grpc-client
I0427 07:17:06.624337 135711971115008 k8s_base_runner.py:888] Deployment psm-grpc-client deleted
I0427 07:17:06.624641 135711971115008 k8s_base_runner.py:471] Revoking roles/iam.workloadIdentityUser from serviceAccount:grpc-testing.svc.id.goog[psm-interop-client-20240427-0712-rj6ui/psm-grpc-client] for GCP Service Account xds-k8s-interop-tests@grpc-testing.iam.gserviceaccount.com
I0427 07:17:07.118207 135711971115008 k8s_base_runner.py:907] Deleting service account psm-grpc-client
I0427 07:17:07.232642 135711971115008 k8s_base_runner.py:921] Service account psm-grpc-client deleted
I0427 07:17:07.232876 135711971115008 k8s_base_runner.py:924] Deleting namespace psm-interop-client-20240427-0712-rj6ui
I0427 07:17:37.404955 135711971115008 k8s_base_runner.py:941] Namespace psm-interop-client-20240427-0712-rj6ui deleted
I0427 07:17:37.405195 135711971115008 k8s_xds_client_runner.py:119] Deploying xDS test client "psm-grpc-client" to k8s namespace psm-interop-client-20240427-0712-rj6ui: server_target=xds:///psm-grpc-server:13901 rpc=UnaryCall qps=25 metadata='' secure_mode=False print_response=False
I0427 07:17:37.405515 135711971115008 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-client:
https://console.cloud.google.com/logs/query;query=resource.type%3D%22k8s_container%22%0Aresource.labels.project_id%3D%22grpc-testing%22%0Aresource.labels.container_name%3D%22psm-grpc-client%22%0Aresource.labels.namespace_name%3D%22psm-interop-client-20240427-0712-rj6ui%22;timeRange=2024-04-27T07:17:37.405416Z%2F2024-04-27T07:47:37.405416Z?project=grpc-testing
I0427 07:17:37.406085 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/namespace.yaml:
---
apiVersion: v1
kind: Namespace
metadata:
name: psm-interop-client-20240427-0712-rj6ui
labels:
name: psm-interop-client-20240427-0712-rj6ui
owner: xds-k8s-interop-test
...
I0427 07:17:37.464409 135711971115008 k8s_base_runner.py:367] Namespace psm-interop-client-20240427-0712-rj6ui created
I0427 07:17:37.464656 135711971115008 k8s_base_runner.py:452] Granting roles/iam.workloadIdentityUser to serviceAccount:grpc-testing.svc.id.goog[psm-interop-client-20240427-0712-rj6ui/psm-grpc-client] for GCP Service Account xds-k8s-interop-tests@grpc-testing.iam.gserviceaccount.com
I0427 07:17:38.151519 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/service-account.yaml:
---
apiVersion: v1
kind: ServiceAccount
metadata:
name: psm-grpc-client
namespace: psm-interop-client-20240427-0712-rj6ui
labels:
owner: xds-k8s-interop-test
annotations:
iam.gke.io/gcp-service-account: xds-k8s-interop-tests@grpc-testing.iam.gserviceaccount.com
...
I0427 07:17:38.204823 135711971115008 k8s_base_runner.py:367] ServiceAccount psm-grpc-client created
I0427 07:17:38.207531 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/client.deployment.yaml:
---
apiVersion: apps/v1
kind: Deployment
metadata:
name: psm-grpc-client
namespace: psm-interop-client-20240427-0712-rj6ui
labels:
app: psm-grpc-client
deployment_id: psm-grpc-client-89dkpjyw
owner: xds-k8s-interop-test
spec:
replicas: 1
selector:
matchLabels:
app: psm-grpc-client
deployment_id: psm-grpc-client-89dkpjyw
template:
metadata:
labels:
app: psm-grpc-client
deployment_id: psm-grpc-client-89dkpjyw
owner: xds-k8s-interop-test
spec:
serviceAccountName: psm-grpc-client
containers:
- name: psm-grpc-client
image: us-docker.pkg.dev/grpc-testing/psm-interop/node-client:c6391f3db078215cdfa8fdab35c5bbc2785f7956
imagePullPolicy: Always
startupProbe:
tcpSocket:
port: 8079
periodSeconds: 3
failureThreshold: 1000
args:
- "--server=xds:///psm-grpc-server:13901"
- "--stats_port=8079"
- "--qps=25"
- "--rpc=UnaryCall"
- "--metadata="
- "--print_response=False"
ports:
- containerPort: 8079
env:
- name: GRPC_XDS_BOOTSTRAP
value: "/tmp/grpc-xds/td-grpc-bootstrap.json"
- name: GRPC_XDS_EXPERIMENTAL_ENABLE_RING_HASH
value: "true"
- name: GRPC_XDS_EXPERIMENTAL_ENABLE_RETRY
value: "true"
- name: GRPC_EXPERIMENTAL_ENABLE_OUTLIER_DETECTION
value: "true"
- name: GRPC_EXPERIMENTAL_XDS_CUSTOM_LB_CONFIG
value: "true"
- name: GRPC_EXPERIMENTAL_XDS_ENABLE_OVERRIDE_HOST
value: "true"
volumeMounts:
- mountPath: /tmp/grpc-xds/
name: grpc-td-conf
readOnly: true
resources:
limits:
cpu: 800m
memory: 512Mi
requests:
cpu: 100m
memory: 512Mi
initContainers:
- name: grpc-td-init
image: us-docker.pkg.dev/grpc-testing/trafficdirector/td-grpc-bootstrap:2bf1b5ed00f852ffea8d24759c6fa673acc9ef10
imagePullPolicy: Always
args:
- "--output=/tmp/bootstrap/td-grpc-bootstrap.json"
- "--vpc-network-name=default-vpc"
resources:
limits:
cpu: 100m
memory: 100Mi
requests:
cpu: 10m
memory: 100Mi
volumeMounts:
- mountPath: /tmp/bootstrap/
name: grpc-td-conf
volumes:
- name: grpc-td-conf
emptyDir:
medium: Memory
...
I0427 07:17:38.277174 135711971115008 k8s_base_runner.py:367] Deployment psm-grpc-client created
I0427 07:17:38.277390 135711971115008 k8s_base_runner.py:962] Waiting for deployment psm-grpc-client to initialize 1 pod(s)
I0427 07:17:38.381602 135711971115008 k8s_base_runner.py:972] Deployment psm-grpc-client initialized 1 pod(s): ['psm-grpc-client-6795ffc767-wmzzm']
I0427 07:17:38.381870 135711971115008 k8s_base_runner.py:982] Waiting for pod psm-grpc-client-6795ffc767-wmzzm to start
I0427 07:17:41.610053 135711971115008 k8s_base_runner.py:985] Pod psm-grpc-client-6795ffc767-wmzzm ready, IP: 10.120.11.235
I0427 07:17:41.610282 135711971115008 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-client-6795ffc767-wmzzm to subsetting_test/test_app_logs/psm-interop-client-20240427-0712-rj6ui_psm-grpc-client-6795ffc767-wmzzm.log
I0427 07:17:41.610669 135711596455488 k8s_log_collector.py:71] [ns/psm-interop-client-20240427-0712-rj6ui] Starting log collection thread 135711596455488 for psm-grpc-client-6795ffc767-wmzzm
I0427 07:17:41.611002 135711971115008 k8s_base_runner.py:944] Waiting for deployment psm-grpc-client to report 1 available replica(s)
I0427 07:17:42.735918 135711971115008 k8s_base_runner.py:953] Deployment psm-grpc-client has 1 replicas available
I0427 07:17:42.736333 135711971115008 client_app.py:292] [psm-grpc-client-6795ffc767-wmzzm] ADS: Waiting for active calls to xDS control plane to trafficdirector.googleapis.com:443
I0427 07:17:42.882215 135711971115008 client_app.py:320] [psm-grpc-client-6795ffc767-wmzzm] xDS control plane channel:
I0427 07:17:44.922092 135711971115008 client_app.py:331] [psm-grpc-client-6795ffc767-wmzzm] Detected active calls to xDS control plane trafficdirector.googleapis.com:443, channel:
I0427 07:17:44.922480 135711971115008 client_app.py:302] [psm-grpc-client-6795ffc767-wmzzm] ADS: Detected active calls to xDS control plane trafficdirector.googleapis.com:443
I0427 07:17:44.922851 135711971115008 client_app.py:252] [psm-grpc-client-6795ffc767-wmzzm] Waiting to report a READY channel to xds:///psm-grpc-server:13901
I0427 07:17:44.957397 135711971115008 client_app.py:379] [psm-grpc-client-6795ffc767-wmzzm] Server channel:
I0427 07:17:44.995946 135711971115008 client_app.py:392] [psm-grpc-client-6795ffc767-wmzzm] Found subchannel in state READY:
I0427 07:17:44.996335 135711971115008 client_app.py:263] [psm-grpc-client-6795ffc767-wmzzm] Channel to xds:///psm-grpc-server:13901 transitioned to state READY:
I0427 07:17:45.038861 135711971115008 subsetting_test.py:88] Client 1 received endpoints (len=4): ['10.120.10.90:8080', '10.120.9.2:8080', '10.120.17.14:8080', '10.120.16.123:8080']
I0427 07:17:45.039275 135711971115008 grpc.py:75] [psm-grpc-client-6795ffc767-wmzzm:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 200, 'timeoutSec': 1200}), wait_for_ready=True, timeout=1200)
I0427 07:17:53.153697 135711971115008 xds_k8s_testcase.py:669] [psm-grpc-client-6795ffc767-wmzzm] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-5645595cf5-nls8h: 50
psm-grpc-server-5645595cf5-9sjpf: 50
psm-grpc-server-5645595cf5-dqtbq: 50
psm-grpc-server-5645595cf5-jwthf: 50
rpcs_by_method:
UnaryCall:
psm-grpc-server-5645595cf5-nls8h: 50
psm-grpc-server-5645595cf5-9sjpf: 50
psm-grpc-server-5645595cf5-dqtbq: 50
psm-grpc-server-5645595cf5-jwthf: 50
I0427 07:17:53.154227 135711971115008 k8s_base_runner.py:873] Deleting deployment psm-grpc-client
I0427 07:18:33.467436 135711971115008 k8s_base_runner.py:888] Deployment psm-grpc-client deleted
I0427 07:18:33.467703 135711971115008 k8s_base_runner.py:471] Revoking roles/iam.workloadIdentityUser from serviceAccount:grpc-testing.svc.id.goog[psm-interop-client-20240427-0712-rj6ui/psm-grpc-client] for GCP Service Account xds-k8s-interop-tests@grpc-testing.iam.gserviceaccount.com
I0427 07:18:34.144841 135711971115008 k8s_base_runner.py:907] Deleting service account psm-grpc-client
I0427 07:18:34.261604 135711971115008 k8s_base_runner.py:921] Service account psm-grpc-client deleted
I0427 07:18:34.261855 135711971115008 k8s_base_runner.py:924] Deleting namespace psm-interop-client-20240427-0712-rj6ui
I0427 07:19:04.437314 135711971115008 k8s_base_runner.py:941] Namespace psm-interop-client-20240427-0712-rj6ui deleted
I0427 07:19:04.437577 135711971115008 k8s_xds_client_runner.py:119] Deploying xDS test client "psm-grpc-client" to k8s namespace psm-interop-client-20240427-0712-rj6ui: server_target=xds:///psm-grpc-server:13901 rpc=UnaryCall qps=25 metadata='' secure_mode=False print_response=False
I0427 07:19:04.437994 135711971115008 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-client:
https://console.cloud.google.com/logs/query;query=resource.type%3D%22k8s_container%22%0Aresource.labels.project_id%3D%22grpc-testing%22%0Aresource.labels.container_name%3D%22psm-grpc-client%22%0Aresource.labels.namespace_name%3D%22psm-interop-client-20240427-0712-rj6ui%22;timeRange=2024-04-27T07:19:04.437878Z%2F2024-04-27T07:49:04.437878Z?project=grpc-testing
I0427 07:19:04.438560 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/namespace.yaml:
---
apiVersion: v1
kind: Namespace
metadata:
name: psm-interop-client-20240427-0712-rj6ui
labels:
name: psm-interop-client-20240427-0712-rj6ui
owner: xds-k8s-interop-test
...
I0427 07:19:04.501684 135711971115008 k8s_base_runner.py:367] Namespace psm-interop-client-20240427-0712-rj6ui created
I0427 07:19:04.501906 135711971115008 k8s_base_runner.py:452] Granting roles/iam.workloadIdentityUser to serviceAccount:grpc-testing.svc.id.goog[psm-interop-client-20240427-0712-rj6ui/psm-grpc-client] for GCP Service Account xds-k8s-interop-tests@grpc-testing.iam.gserviceaccount.com
I0427 07:19:05.141950 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/service-account.yaml:
---
apiVersion: v1
kind: ServiceAccount
metadata:
name: psm-grpc-client
namespace: psm-interop-client-20240427-0712-rj6ui
labels:
owner: xds-k8s-interop-test
annotations:
iam.gke.io/gcp-service-account: xds-k8s-interop-tests@grpc-testing.iam.gserviceaccount.com
...
I0427 07:19:05.202900 135711971115008 k8s_base_runner.py:367] ServiceAccount psm-grpc-client created
I0427 07:19:05.205614 135711971115008 k8s_base_runner.py:347] Rendered template kubernetes-manifests/client.deployment.yaml:
---
apiVersion: apps/v1
kind: Deployment
metadata:
name: psm-grpc-client
namespace: psm-interop-client-20240427-0712-rj6ui
labels:
app: psm-grpc-client
deployment_id: psm-grpc-client-aulmcare
owner: xds-k8s-interop-test
spec:
replicas: 1
selector:
matchLabels:
app: psm-grpc-client
deployment_id: psm-grpc-client-aulmcare
template:
metadata:
labels:
app: psm-grpc-client
deployment_id: psm-grpc-client-aulmcare
owner: xds-k8s-interop-test
spec:
serviceAccountName: psm-grpc-client
containers:
- name: psm-grpc-client
image: us-docker.pkg.dev/grpc-testing/psm-interop/node-client:c6391f3db078215cdfa8fdab35c5bbc2785f7956
imagePullPolicy: Always
startupProbe:
tcpSocket:
port: 8079
periodSeconds: 3
failureThreshold: 1000
args:
- "--server=xds:///psm-grpc-server:13901"
- "--stats_port=8079"
- "--qps=25"
- "--rpc=UnaryCall"
- "--metadata="
- "--print_response=False"
ports:
- containerPort: 8079
env:
- name: GRPC_XDS_BOOTSTRAP
value: "/tmp/grpc-xds/td-grpc-bootstrap.json"
- name: GRPC_XDS_EXPERIMENTAL_ENABLE_RING_HASH
value: "true"
- name: GRPC_XDS_EXPERIMENTAL_ENABLE_RETRY
value: "true"
- name: GRPC_EXPERIMENTAL_ENABLE_OUTLIER_DETECTION
value: "true"
- name: GRPC_EXPERIMENTAL_XDS_CUSTOM_LB_CONFIG
value: "true"
- name: GRPC_EXPERIMENTAL_XDS_ENABLE_OVERRIDE_HOST
value: "true"
volumeMounts:
- mountPath: /tmp/grpc-xds/
name: grpc-td-conf
readOnly: true
resources:
limits:
cpu: 800m
memory: 512Mi
requests:
cpu: 100m
memory: 512Mi
initContainers:
- name: grpc-td-init
image: us-docker.pkg.dev/grpc-testing/trafficdirector/td-grpc-bootstrap:2bf1b5ed00f852ffea8d24759c6fa673acc9ef10
imagePullPolicy: Always
args:
- "--output=/tmp/bootstrap/td-grpc-bootstrap.json"
- "--vpc-network-name=default-vpc"
resources:
limits:
cpu: 100m
memory: 100Mi
requests:
cpu: 10m
memory: 100Mi
volumeMounts:
- mountPath: /tmp/bootstrap/
name: grpc-td-conf
volumes:
- name: grpc-td-conf
emptyDir:
medium: Memory
...
I0427 07:19:05.277259 135711971115008 k8s_base_runner.py:367] Deployment psm-grpc-client created
I0427 07:19:05.277511 135711971115008 k8s_base_runner.py:962] Waiting for deployment psm-grpc-client to initialize 1 pod(s)
I0427 07:19:05.386714 135711971115008 k8s_base_runner.py:972] Deployment psm-grpc-client initialized 1 pod(s): ['psm-grpc-client-d4f7bf8cf-v2ttg']
I0427 07:19:05.386956 135711971115008 k8s_base_runner.py:982] Waiting for pod psm-grpc-client-d4f7bf8cf-v2ttg to start
I0427 07:19:08.645175 135711971115008 k8s_base_runner.py:985] Pod psm-grpc-client-d4f7bf8cf-v2ttg ready, IP: 10.120.17.15
I0427 07:19:08.645421 135711971115008 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-client-d4f7bf8cf-v2ttg to subsetting_test/test_app_logs/psm-interop-client-20240427-0712-rj6ui_psm-grpc-client-d4f7bf8cf-v2ttg.log
I0427 07:19:08.645773 135711596455488 k8s_log_collector.py:71] [ns/psm-interop-client-20240427-0712-rj6ui] Starting log collection thread 135711596455488 for psm-grpc-client-d4f7bf8cf-v2ttg
I0427 07:19:08.645957 135711971115008 k8s_base_runner.py:944] Waiting for deployment psm-grpc-client to report 1 available replica(s)
I0427 07:19:11.873575 135711971115008 k8s_base_runner.py:953] Deployment psm-grpc-client has 1 replicas available
I0427 07:19:11.873977 135711971115008 client_app.py:292] [psm-grpc-client-d4f7bf8cf-v2ttg] ADS: Waiting for active calls to xDS control plane to trafficdirector.googleapis.com:443
I0427 07:19:12.031206 135711971115008 client_app.py:320] [psm-grpc-client-d4f7bf8cf-v2ttg] xDS control plane channel:
I0427 07:19:14.071814 135711971115008 client_app.py:331] [psm-grpc-client-d4f7bf8cf-v2ttg] Detected active calls to xDS control plane trafficdirector.googleapis.com:443, channel:
I0427 07:19:14.072170 135711971115008 client_app.py:302] [psm-grpc-client-d4f7bf8cf-v2ttg] ADS: Detected active calls to xDS control plane trafficdirector.googleapis.com:443
I0427 07:19:14.072402 135711971115008 client_app.py:252] [psm-grpc-client-d4f7bf8cf-v2ttg] Waiting to report a READY channel to xds:///psm-grpc-server:13901
I0427 07:19:14.108012 135711971115008 client_app.py:379] [psm-grpc-client-d4f7bf8cf-v2ttg] Server channel:
I0427 07:19:14.147293 135711971115008 client_app.py:392] [psm-grpc-client-d4f7bf8cf-v2ttg] Found subchannel in state READY:
I0427 07:19:14.147701 135711971115008 client_app.py:263] [psm-grpc-client-d4f7bf8cf-v2ttg] Channel to xds:///psm-grpc-server:13901 transitioned to state READY:
I0427 07:19:14.193772 135711971115008 subsetting_test.py:88] Client 2 received endpoints (len=4): ['10.120.17.14:8080', '10.120.14.152:8080', '10.120.16.123:8080', '10.120.15.249:8080']
I0427 07:19:14.194442 135711971115008 grpc.py:75] [psm-grpc-client-d4f7bf8cf-v2ttg:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 200, 'timeoutSec': 1200}), wait_for_ready=True, timeout=1200)
I0427 07:19:22.285094 135711971115008 xds_k8s_testcase.py:669] [psm-grpc-client-d4f7bf8cf-v2ttg] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-5645595cf5-wzjvr: 50
psm-grpc-server-5645595cf5-q6bwx: 50
psm-grpc-server-5645595cf5-jwthf: 50
psm-grpc-server-5645595cf5-9sjpf: 50
rpcs_by_method:
UnaryCall:
psm-grpc-server-5645595cf5-wzjvr: 50
psm-grpc-server-5645595cf5-q6bwx: 50
psm-grpc-server-5645595cf5-jwthf: 50
psm-grpc-server-5645595cf5-9sjpf: 50
I0427 07:19:22.285378 135711971115008 xds_k8s_testcase.py:304] --- Finished subTest SubsettingTest.test_subsetting_basic.07_start_test_client ---
I0427 07:19:22.285499 135711971115008 xds_k8s_testcase.py:299] --- Starting subTest SubsettingTest.test_subsetting_basic.08_log_rpc_distribution ---
I0427 07:19:22.285596 135711971115008 subsetting_test.py:115] RPC distribution (len=6): [('psm-grpc-server-5645595cf5-jwthf', 150), ('psm-grpc-server-5645595cf5-wzjvr', 100), ('psm-grpc-server-5645595cf5-q6bwx', 100), ('psm-grpc-server-5645595cf5-dqtbq', 100), ('psm-grpc-server-5645595cf5-9sjpf', 100), ('psm-grpc-server-5645595cf5-nls8h', 50)]
I0427 07:19:22.285673 135711971115008 subsetting_test.py:124] Peak=150 Mean=100.0 Peak-to-Mean-Ratio=1.50
I0427 07:19:22.285738 135711971115008 xds_k8s_testcase.py:304] --- Finished subTest SubsettingTest.test_subsetting_basic.08_log_rpc_distribution ---
I0427 07:19:22.285852 135711971115008 xds_k8s_testcase.py:755] ----- TestMethod SubsettingTest.test_subsetting_basic teardown -----
I0427 07:19:22.459660 135711971115008 traffic_director.py:674] Deleting Forwarding rule "psm-interop-forwarding-rule-20240427-0712-rj6ui"
I0427 07:19:23.345674 135711971115008 compute.py:614] Waiting 600 sec for compute operation id: operation-1714202362471-6170ed6e36573-ea6c4cf3-607112b0
I0427 07:19:36.318457 135711971115008 traffic_director.py:713] Deleting alternative Forwarding rule "psm-interop-forwarding-rule-alt-20240427-0712-rj6ui"
I0427 07:19:36.413086 135711971115008 traffic_director.py:605] Deleting HTTP Target proxy "psm-interop-target-proxy-20240427-0712-rj6ui"
I0427 07:19:36.950716 135711971115008 traffic_director.py:593] Deleting Target GRPC proxy "psm-interop-target-proxy-20240427-0712-rj6ui"
I0427 07:19:37.533079 135711971115008 compute.py:614] Waiting 600 sec for compute operation id: operation-1714202376953-6170ed7c05fc1-f0ae40e3-a122cd10
I0427 07:19:39.791202 135711971115008 traffic_director.py:633] Deleting alternative Target GRPC proxy "psm-interop-target-proxy-alt-20240427-0712-rj6ui"
I0427 07:19:40.050675 135711971115008 traffic_director.py:525] Deleting URL Map "psm-interop-url-map-20240427-0712-rj6ui"
I0427 07:19:40.808527 135711971115008 compute.py:614] Waiting 600 sec for compute operation id: operation-1714202380055-6170ed7efb39b-c25992ba-9c29369c
I0427 07:19:43.073206 135711971115008 traffic_director.py:561] Deleting alternative URL Map "psm-interop-url-map-alt-20240427-0712-rj6ui"
I0427 07:19:43.548755 135711971115008 traffic_director.py:243] Deleting Backend Service "psm-interop-backend-service-20240427-0712-rj6ui"
I0427 07:19:44.325100 135711971115008 compute.py:614] Waiting 600 sec for compute operation id: operation-1714202383553-6170ed82515bb-3cb46aad-a610961e
I0427 07:20:08.002175 135711971115008 traffic_director.py:332] Deleting Alternative Backend Service "psm-interop-backend-service-alt-20240427-0712-rj6ui"
I0427 07:20:08.303375 135711971115008 traffic_director.py:405] Deleting Affinity Backend Service "psm-interop-backend-service-affinity-20240427-0712-rj6ui"
I0427 07:20:08.640110 135711971115008 traffic_director.py:202] Deleting Health Check "psm-interop-health-check-20240427-0712-rj6ui"
I0427 07:20:09.321731 135711971115008 compute.py:614] Waiting 600 sec for compute operation id: operation-1714202408723-6170ed9a52264-79489bc5-7821c01b
I0427 07:20:13.703743 135711971115008 k8s_base_runner.py:873] Deleting deployment psm-grpc-client
I0427 07:20:54.131837 135711971115008 k8s_base_runner.py:888] Deployment psm-grpc-client deleted
I0427 07:20:54.132191 135711971115008 k8s_base_runner.py:471] Revoking roles/iam.workloadIdentityUser from serviceAccount:grpc-testing.svc.id.goog[psm-interop-client-20240427-0712-rj6ui/psm-grpc-client] for GCP Service Account xds-k8s-interop-tests@grpc-testing.iam.gserviceaccount.com
I0427 07:20:54.740937 135711971115008 k8s_base_runner.py:907] Deleting service account psm-grpc-client
I0427 07:20:54.856319 135711971115008 k8s_base_runner.py:921] Service account psm-grpc-client deleted
I0427 07:20:54.856557 135711971115008 k8s_base_runner.py:924] Deleting namespace psm-interop-client-20240427-0712-rj6ui
I0427 07:21:25.059130 135711971115008 k8s_base_runner.py:941] Namespace psm-interop-client-20240427-0712-rj6ui deleted
I0427 07:21:25.059416 135711971115008 k8s_base_runner.py:873] Deleting deployment psm-grpc-server
I0427 07:21:35.328924 135711971115008 k8s_base_runner.py:888] Deployment psm-grpc-server deleted
I0427 07:21:35.329221 135711971115008 k8s_base_runner.py:891] Deleting service psm-grpc-server
I0427 07:21:35.447165 135711971115008 k8s_base_runner.py:904] Service psm-grpc-server deleted
I0427 07:21:35.447399 135711971115008 k8s_base_runner.py:471] Revoking roles/iam.workloadIdentityUser from serviceAccount:grpc-testing.svc.id.goog[psm-interop-server-20240427-0712-rj6ui/psm-grpc-server] for GCP Service Account xds-k8s-interop-tests@grpc-testing.iam.gserviceaccount.com
I0427 07:21:36.170972 135711971115008 k8s_base_runner.py:907] Deleting service account psm-grpc-server
I0427 07:21:36.298880 135711971115008 k8s_base_runner.py:921] Service account psm-grpc-server deleted
I0427 07:21:36.299114 135711971115008 k8s_base_runner.py:924] Deleting namespace psm-interop-server-20240427-0712-rj6ui
I0427 07:23:36.764007 135711971115008 k8s_base_runner.py:941] Namespace psm-interop-server-20240427-0712-rj6ui deleted
I0427 07:23:36.764413 135711971115008 xds_k8s_testcase.py:779] ----- Test client/server logs -----
I0427 07:23:36.764724 135711971115008 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-client-58edkzy0:
https://console.cloud.google.com/logs/query;query=resource.type%3D%22k8s_container%22%0Aresource.labels.project_id%3D%22grpc-testing%22%0Aresource.labels.container_name%3D%22psm-grpc-client%22%0Aresource.labels.namespace_name%3D%22psm-interop-client-20240427-0712-rj6ui%22%0Alabels.%22k8s-pod%2Fdeployment_id%22%3D%22psm-grpc-client-58edkzy0%22;timeRange=2024-04-27T07:14:21.639142Z%2F2024-04-27T07:17:37.405157Z;cursorTimestamp=2024-04-27T07:14:29.116446Z?project=grpc-testing
I0427 07:23:36.764937 135711971115008 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-client-89dkpjyw:
https://console.cloud.google.com/logs/query;query=resource.type%3D%22k8s_container%22%0Aresource.labels.project_id%3D%22grpc-testing%22%0Aresource.labels.container_name%3D%22psm-grpc-client%22%0Aresource.labels.namespace_name%3D%22psm-interop-client-20240427-0712-rj6ui%22%0Alabels.%22k8s-pod%2Fdeployment_id%22%3D%22psm-grpc-client-89dkpjyw%22;timeRange=2024-04-27T07:17:37.405409Z%2F2024-04-27T07:19:04.437532Z;cursorTimestamp=2024-04-27T07:17:42.736158Z?project=grpc-testing
I0427 07:23:36.765111 135711971115008 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-client-aulmcare:
https://console.cloud.google.com/logs/query;query=resource.type%3D%22k8s_container%22%0Aresource.labels.project_id%3D%22grpc-testing%22%0Aresource.labels.container_name%3D%22psm-grpc-client%22%0Aresource.labels.namespace_name%3D%22psm-interop-client-20240427-0712-rj6ui%22%0Alabels.%22k8s-pod%2Fdeployment_id%22%3D%22psm-grpc-client-aulmcare%22;timeRange=2024-04-27T07:19:04.437870Z%2F2024-04-27T07:21:25.059385Z;cursorTimestamp=2024-04-27T07:19:11.873795Z?project=grpc-testing
I0427 07:23:36.765261 135711971115008 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-server-vw6qlnhw:
https://console.cloud.google.com/logs/query;query=resource.type%3D%22k8s_container%22%0Aresource.labels.project_id%3D%22grpc-testing%22%0Aresource.labels.container_name%3D%22psm-grpc-server%22%0Aresource.labels.namespace_name%3D%22psm-interop-server-20240427-0712-rj6ui%22%0Alabels.%22k8s-pod%2Fdeployment_id%22%3D%22psm-grpc-server-vw6qlnhw%22;timeRange=2024-04-27T07:13:18.475596Z%2F2024-04-27T07:23:36.764243Z;cursorTimestamp=2024-04-27T07:13:28.463090Z?project=grpc-testing
[ OK ] SubsettingTest.test_subsetting_basic
I0427 07:23:36.765510 135711971115008 base_testcase.py:67] ----- PSM Test Case PASSED: SubsettingTest.test_subsetting_basic -----
----------------------------------------------------------------------
Ran 1 test in 683.197s
OK
+ [07:23:37 UTC] Cmd finished: python