Warning: Permanently added 'localhost' (ED25519) to the list of known hosts.
Warning: Permanently added 'localhost' (ED25519) to the list of known hosts.
Warning: Permanently added 'localhost' (ED25519) to the list of known hosts.
[09:11:06 PDT] Transferring environment variable script to build VM
[09:11:07 PDT] Transferring kokoro_log_reader.py to build VM
[09:11:07 PDT] Transferring source code to build VM
[09:11:16 PDT] Executing build script on build VM



[ID: 7265131] Executing command via SSH:
export KOKORO_BUILD_NUMBER="9"
export KOKORO_JOB_NAME="grpc/core/master/linux/psm-csm-python"
source /tmpfs/kokoro-env_vars.sh; cd /tmpfs/src/ ; chmod 755 github/grpc/tools/internal_ci/linux/psm-csm-python.sh ; PYTHON_3_VERSION="$(pyenv which python3 2> /dev/null || which python3)" ; PYTHON_2_VERSION="$(pyenv which python2 2> /dev/null || which python2)" ; if "$PYTHON_3_VERSION" -c "import psutil" ; then KOKORO_PYTHON_COMMAND="$PYTHON_3_VERSION" ; else KOKORO_PYTHON_COMMAND="$PYTHON_2_VERSION" ; fi > /dev/null 2>&1 ; echo "export KOKORO_PYTHON_COMMAND="$KOKORO_PYTHON_COMMAND"" > "$HOME/.kokoro_python_vars" ; nohup bash -c "( rm -f /tmpfs/kokoro_build_exit_code ; github/grpc/tools/internal_ci/linux/psm-csm-python.sh ; echo \${PIPESTATUS[0]} > /tmpfs/kokoro_build_exit_code ) > /tmpfs/kokoro_build.log 2>&1" > /dev/null 2>&1 & echo $! > /tmpfs/kokoro_build.pid ; source "$HOME/.kokoro_python_vars" ; "$KOKORO_PYTHON_COMMAND" /tmpfs/kokoro_log_reader.py /tmpfs/kokoro_build.log /tmpfs/kokoro_build_exit_code /tmpfs/kokoro_build.pid /tmpfs/kokoro_log_reader.pid --start_byte 0

Sourcing test driver install script from: https://raw.githubusercontent.com/XuanWang-Amos/psm-interop/add_python_ssa_test/.kokoro/psm_interop_kokoro_lib.sh
Activated GKE cluster: GKE_CLUSTER_NAME=psm-interop-csm GKE_CLUSTER_REGION=us-central1
Kokoro Ubuntu version:
No LSB modules are available.
Distributor ID: Ubuntu
Description: Ubuntu 22.04.3 LTS
Release: 22.04
Codename: jammy
Python 3.10.12
pip 22.0.2 from /usr/lib/python3/dist-packages/pip (python 3.10)
Sponge properties:
TESTS_FORMAT_VERSION,2
TESTGRID_EXCLUDE,0
GIT_ORIGIN_URL,https://github.com/XuanWang-Amos/grpc.git
GIT_COMMIT_SHORT,64414d1b02
(Reading database ... (Reading database ... 5%(Reading database ... 10%(Reading database ... 15%(Reading database ... 20%(Reading database ... 25%(Reading database ... 30%(Reading database ... 35%(Reading database ... 40%(Reading database ... 45%(Reading database ... 50%(Reading database ... 55%(Reading database ... 60%(Reading database ... 65%(Reading database ... 70%(Reading database ... 75%(Reading database ... 80%(Reading database ... 85%(Reading database ... 90%(Reading database ... 95%(Reading database ... 100%(Reading database ... 130042 files and directories currently installed.)
Removing needrestart (3.5-5ubuntu2.1) ...
Processing triggers for man-db (2.10.2-1) ...
W: https://packages.cloud.google.com/apt/dists/cloud-sdk/InRelease: Key is stored in legacy trusted.gpg keyring (/etc/apt/trusted.gpg), see the DEPRECATION section in apt-key(8) for details.
W: https://download.docker.com/linux/ubuntu/dists/jammy/InRelease: Key is stored in legacy trusted.gpg keyring (/etc/apt/trusted.gpg), see the DEPRECATION section in apt-key(8) for details.
(Reading database ... (Reading database ... 5%(Reading database ... 10%(Reading database ... 15%(Reading database ... 20%(Reading database ... 25%(Reading database ... 30%(Reading database ... 35%(Reading database ... 40%(Reading database ... 45%(Reading database ... 50%(Reading database ... 55%(Reading database ... 60%(Reading database ... 65%(Reading database ... 70%(Reading database ... 75%(Reading database ... 80%(Reading database ... 85%(Reading database ... 90%(Reading database ... 95%(Reading database ... 100%(Reading database ... 129987 files and directories currently installed.)
Removing libintl-xs-perl (1.26-3build2) ...
Removing libintl-perl (1.26-3build2) ...
Removing libmodule-find-perl (0.15-1) ...
Removing libmodule-scandeps-perl (1.31-1) ...
Removing libproc-processtable-perl:amd64 (0.634-1build1) ...
Removing libsort-naturally-perl (1.03-2) ...
Removing libterm-readkey-perl (2.38-1build4) ...
Selecting previously unselected package google-cloud-cli-gke-gcloud-auth-plugin.
(Reading database ... (Reading database ... 5%(Reading database ... 10%(Reading database ... 15%(Reading database ... 20%(Reading database ... 25%(Reading database ... 30%(Reading database ... 35%(Reading database ... 40%(Reading database ... 45%(Reading database ... 50%(Reading database ... 55%(Reading database ... 60%(Reading database ... 65%(Reading database ... 70%(Reading database ... 75%(Reading database ... 80%(Reading database ... 85%(Reading database ... 90%(Reading database ... 95%(Reading database ... 100%(Reading database ... 129587 files and directories currently installed.)
Preparing to unpack .../0-google-cloud-cli-gke-gcloud-auth-plugin_471.0.0-0_amd64.deb ...
Unpacking google-cloud-cli-gke-gcloud-auth-plugin (471.0.0-0) ...
Selecting previously unselected package google-cloud-sdk-gke-gcloud-auth-plugin.
Preparing to unpack .../1-google-cloud-sdk-gke-gcloud-auth-plugin_467.0.0-0_all.deb ...
Unpacking google-cloud-sdk-gke-gcloud-auth-plugin (467.0.0-0) ...
Selecting previously unselected package kubectl.
Preparing to unpack .../2-kubectl_1%3a471.0.0-0_amd64.deb ...
Unpacking kubectl (1:471.0.0-0) ...
Selecting previously unselected package python3-pip-whl.
Preparing to unpack .../3-python3-pip-whl_22.0.2+dfsg-1ubuntu0.4_all.deb ...
Unpacking python3-pip-whl (22.0.2+dfsg-1ubuntu0.4) ...
Selecting previously unselected package python3-setuptools-whl.
Preparing to unpack .../4-python3-setuptools-whl_59.6.0-1.2ubuntu0.22.04.1_all.deb ...
Unpacking python3-setuptools-whl (59.6.0-1.2ubuntu0.22.04.1) ...
Selecting previously unselected package python3.10-venv.
Preparing to unpack .../5-python3.10-venv_3.10.12-1~22.04.3_amd64.deb ...
Unpacking python3.10-venv (3.10.12-1~22.04.3) ...
Setting up python3-setuptools-whl (59.6.0-1.2ubuntu0.22.04.1) ...
Setting up python3-pip-whl (22.0.2+dfsg-1ubuntu0.4) ...
Setting up google-cloud-cli-gke-gcloud-auth-plugin (471.0.0-0) ...
Setting up google-cloud-sdk-gke-gcloud-auth-plugin (467.0.0-0) ...
Setting up kubectl (1:471.0.0-0) ...
Setting up python3.10-venv (3.10.12-1~22.04.3) ...
Processing triggers for man-db (2.10.2-1) ...
Fetching cluster endpoint and auth data.
kubeconfig entry generated for psm-interop-csm.
Cloning driver to https://github.com/XuanWang-Amos/psm-interop.git branch add_python_ssa_test to /tmp/tmp.pWnnYGt0vw/psm-interop
Cloning into '/tmp/tmp.pWnnYGt0vw/psm-interop'...
Install python dependencies
Creating python virtual environment: /tmp/tmp.pWnnYGt0vw/psm-interop/venv
Collecting Mako==1.2.4 (from -r requirements.lock (line 1))
Downloading Mako-1.2.4-py3-none-any.whl.metadata (2.9 kB)
Collecting PyYAML==6.0 (from -r requirements.lock (line 2))
Downloading PyYAML-6.0-cp310-cp310-manylinux_2_5_x86_64.manylinux1_x86_64.manylinux_2_12_x86_64.manylinux2010_x86_64.whl.metadata (2.0 kB)
Collecting absl-py==0.15.0 (from -r requirements.lock (line 3))
Downloading absl_py-0.15.0-py3-none-any.whl.metadata (2.4 kB)
Collecting google-api-python-client==1.12.11 (from -r requirements.lock (line 4))
Downloading google_api_python_client-1.12.11-py2.py3-none-any.whl.metadata (4.2 kB)
Collecting google-cloud-secret-manager==2.15.1 (from -r requirements.lock (line 5))
Downloading google_cloud_secret_manager-2.15.1-py2.py3-none-any.whl.metadata (5.1 kB)
Collecting google-cloud-monitoring==2.18.0 (from -r requirements.lock (line 6))
Downloading google_cloud_monitoring-2.18.0-py2.py3-none-any.whl.metadata (5.6 kB)
Collecting grpcio==1.60.1 (from -r requirements.lock (line 7))
Downloading grpcio-1.60.1-cp310-cp310-manylinux_2_17_x86_64.manylinux2014_x86_64.whl.metadata (4.0 kB)
Collecting grpcio-health-checking==1.60.1 (from -r requirements.lock (line 8))
Downloading grpcio_health_checking-1.60.1-py3-none-any.whl.metadata (1.3 kB)
Collecting grpcio-tools==1.60.1 (from -r requirements.lock (line 9))
Downloading grpcio_tools-1.60.1-cp310-cp310-manylinux_2_17_x86_64.manylinux2014_x86_64.whl.metadata (6.2 kB)
Collecting grpcio-channelz==1.60.1 (from -r requirements.lock (line 10))
Downloading grpcio_channelz-1.60.1-py3-none-any.whl.metadata (1.3 kB)
Collecting kubernetes==27.2.0 (from -r requirements.lock (line 11))
Downloading kubernetes-27.2.0-py2.py3-none-any.whl.metadata (1.5 kB)
Collecting six==1.16.0 (from -r requirements.lock (line 12))
Downloading six-1.16.0-py2.py3-none-any.whl.metadata (1.8 kB)
Collecting tenacity==6.3.1 (from -r requirements.lock (line 13))
Downloading tenacity-6.3.1-py2.py3-none-any.whl.metadata (1.2 kB)
Collecting typing_extensions==4.10.0 (from -r requirements.lock (line 14))
Downloading typing_extensions-4.10.0-py3-none-any.whl.metadata (3.0 kB)
Collecting packaging==23.1 (from -r requirements.lock (line 15))
Downloading packaging-23.1-py3-none-any.whl.metadata (3.1 kB)
Collecting Pygments==2.14.0 (from -r requirements.lock (line 16))
Downloading Pygments-2.14.0-py3-none-any.whl.metadata (1.6 kB)
Collecting python-dateutil==2.8.2 (from -r requirements.lock (line 17))
Downloading python_dateutil-2.8.2-py2.py3-none-any.whl.metadata (8.2 kB)
Collecting protobuf==4.24.1 (from -r requirements.lock (line 18))
Downloading protobuf-4.24.1-cp37-abi3-manylinux2014_x86_64.whl.metadata (540 bytes)
Collecting xds-protos==1.58.0rc1 (from -r requirements.lock (line 19))
Downloading xds_protos-1.58.0rc1-py3-none-any.whl.metadata (1.3 kB)
Collecting cachetools==5.3.1 (from -r requirements.lock (line 21))
Downloading cachetools-5.3.1-py3-none-any.whl.metadata (5.2 kB)
Collecting certifi==2023.7.22 (from -r requirements.lock (line 22))
Downloading certifi-2023.7.22-py3-none-any.whl.metadata (2.2 kB)
Collecting charset-normalizer==3.2.0 (from -r requirements.lock (line 23))
Downloading charset_normalizer-3.2.0-cp310-cp310-manylinux_2_17_x86_64.manylinux2014_x86_64.whl.metadata (31 kB)
Collecting google-api-core==2.11.1 (from -r requirements.lock (line 24))
Downloading google_api_core-2.11.1-py3-none-any.whl.metadata (2.7 kB)
Collecting google-auth==2.22.0 (from -r requirements.lock (line 25))
Downloading google_auth-2.22.0-py2.py3-none-any.whl.metadata (4.2 kB)
Collecting google-auth-httplib2==0.1.0 (from -r requirements.lock (line 26))
Downloading google_auth_httplib2-0.1.0-py2.py3-none-any.whl.metadata (2.1 kB)
Collecting googleapis-common-protos==1.60.0 (from -r requirements.lock (line 27))
Downloading googleapis_common_protos-1.60.0-py2.py3-none-any.whl.metadata (1.5 kB)
Collecting grpc-google-iam-v1==0.12.6 (from -r requirements.lock (line 28))
Downloading grpc_google_iam_v1-0.12.6-py2.py3-none-any.whl.metadata (3.2 kB)
Collecting grpcio-status==1.60.1 (from -r requirements.lock (line 29))
Downloading grpcio_status-1.60.1-py3-none-any.whl.metadata (1.3 kB)
Collecting httplib2==0.22.0 (from -r requirements.lock (line 30))
Downloading httplib2-0.22.0-py3-none-any.whl.metadata (2.6 kB)
Collecting idna==3.4 (from -r requirements.lock (line 31))
Downloading idna-3.4-py3-none-any.whl.metadata (9.8 kB)
Collecting MarkupSafe==2.1.3 (from -r requirements.lock (line 32))
Downloading MarkupSafe-2.1.3-cp310-cp310-manylinux_2_17_x86_64.manylinux2014_x86_64.whl.metadata (3.0 kB)
Collecting oauthlib==3.2.2 (from -r requirements.lock (line 33))
Downloading oauthlib-3.2.2-py3-none-any.whl.metadata (7.5 kB)
Collecting proto-plus==1.22.3 (from -r requirements.lock (line 34))
Downloading proto_plus-1.22.3-py3-none-any.whl.metadata (2.2 kB)
Collecting pyasn1==0.5.0 (from -r requirements.lock (line 35))
Downloading pyasn1-0.5.0-py2.py3-none-any.whl.metadata (8.5 kB)
Collecting pyasn1-modules==0.3.0 (from -r requirements.lock (line 36))
Downloading pyasn1_modules-0.3.0-py2.py3-none-any.whl.metadata (3.6 kB)
Collecting pyparsing==3.1.1 (from -r requirements.lock (line 37))
Downloading pyparsing-3.1.1-py3-none-any.whl.metadata (5.1 kB)
Collecting requests==2.31.0 (from -r requirements.lock (line 38))
Downloading requests-2.31.0-py3-none-any.whl.metadata (4.6 kB)
Collecting requests-oauthlib==1.3.1 (from -r requirements.lock (line 39))
Downloading requests_oauthlib-1.3.1-py2.py3-none-any.whl.metadata (10 kB)
Collecting rsa==4.9 (from -r requirements.lock (line 40))
Downloading rsa-4.9-py3-none-any.whl.metadata (4.2 kB)
Collecting uritemplate==3.0.1 (from -r requirements.lock (line 41))
Downloading uritemplate-3.0.1-py2.py3-none-any.whl.metadata (4.6 kB)
Collecting urllib3==1.26.16 (from -r requirements.lock (line 42))
Downloading urllib3-1.26.16-py2.py3-none-any.whl.metadata (48 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 48.4/48.4 kB 2.5 MB/s eta 0:00:00
Collecting websocket-client==1.6.2 (from -r requirements.lock (line 43))
Downloading websocket_client-1.6.2-py3-none-any.whl.metadata (7.5 kB)
Requirement already satisfied: setuptools in ./venv/lib/python3.10/site-packages (from grpcio-tools==1.60.1->-r requirements.lock (line 9)) (69.2.0)
Downloading Mako-1.2.4-py3-none-any.whl (78 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 78.7/78.7 kB 4.1 MB/s eta 0:00:00
Downloading PyYAML-6.0-cp310-cp310-manylinux_2_5_x86_64.manylinux1_x86_64.manylinux_2_12_x86_64.manylinux2010_x86_64.whl (682 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 682.2/682.2 kB 8.3 MB/s eta 0:00:00
Downloading absl_py-0.15.0-py3-none-any.whl (132 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 132.0/132.0 kB 17.4 MB/s eta 0:00:00
Downloading google_api_python_client-1.12.11-py2.py3-none-any.whl (62 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 62.1/62.1 kB 8.1 MB/s eta 0:00:00
Downloading google_cloud_secret_manager-2.15.1-py2.py3-none-any.whl (100 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 100.4/100.4 kB 12.8 MB/s eta 0:00:00
Downloading google_cloud_monitoring-2.18.0-py2.py3-none-any.whl (325 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 326.0/326.0 kB 27.1 MB/s eta 0:00:00
Downloading grpcio-1.60.1-cp310-cp310-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (5.4 MB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 5.4/5.4 MB 51.8 MB/s eta 0:00:00
Downloading grpcio_health_checking-1.60.1-py3-none-any.whl (18 kB)
Downloading grpcio_tools-1.60.1-cp310-cp310-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (2.8 MB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 2.8/2.8 MB 104.9 MB/s eta 0:00:00
Downloading grpcio_channelz-1.60.1-py3-none-any.whl (23 kB)
Downloading kubernetes-27.2.0-py2.py3-none-any.whl (1.5 MB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.5/1.5 MB 81.5 MB/s eta 0:00:00
Downloading six-1.16.0-py2.py3-none-any.whl (11 kB)
Downloading tenacity-6.3.1-py2.py3-none-any.whl (36 kB)
Downloading typing_extensions-4.10.0-py3-none-any.whl (33 kB)
Downloading packaging-23.1-py3-none-any.whl (48 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 48.9/48.9 kB 6.3 MB/s eta 0:00:00
Downloading Pygments-2.14.0-py3-none-any.whl (1.1 MB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.1/1.1 MB 70.9 MB/s eta 0:00:00
Downloading python_dateutil-2.8.2-py2.py3-none-any.whl (247 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 247.7/247.7 kB 26.8 MB/s eta 0:00:00
Downloading protobuf-4.24.1-cp37-abi3-manylinux2014_x86_64.whl (311 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 311.4/311.4 kB 34.1 MB/s eta 0:00:00
Downloading xds_protos-1.58.0rc1-py3-none-any.whl (1.1 MB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 1.1/1.1 MB 71.7 MB/s eta 0:00:00
Downloading cachetools-5.3.1-py3-none-any.whl (9.3 kB)
Downloading certifi-2023.7.22-py3-none-any.whl (158 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 158.3/158.3 kB 20.8 MB/s eta 0:00:00
Downloading charset_normalizer-3.2.0-cp310-cp310-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (201 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 201.8/201.8 kB 23.8 MB/s eta 0:00:00
Downloading google_api_core-2.11.1-py3-none-any.whl (120 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 120.5/120.5 kB 13.6 MB/s eta 0:00:00
Downloading google_auth-2.22.0-py2.py3-none-any.whl (181 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 181.8/181.8 kB 21.6 MB/s eta 0:00:00
Downloading google_auth_httplib2-0.1.0-py2.py3-none-any.whl (9.3 kB)
Downloading googleapis_common_protos-1.60.0-py2.py3-none-any.whl (227 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 227.6/227.6 kB 26.2 MB/s eta 0:00:00
Downloading grpc_google_iam_v1-0.12.6-py2.py3-none-any.whl (26 kB)
Downloading grpcio_status-1.60.1-py3-none-any.whl (14 kB)
Downloading httplib2-0.22.0-py3-none-any.whl (96 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 96.9/96.9 kB 11.9 MB/s eta 0:00:00
Downloading idna-3.4-py3-none-any.whl (61 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 61.5/61.5 kB 8.1 MB/s eta 0:00:00
Downloading MarkupSafe-2.1.3-cp310-cp310-manylinux_2_17_x86_64.manylinux2014_x86_64.whl (25 kB)
Downloading oauthlib-3.2.2-py3-none-any.whl (151 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 151.7/151.7 kB 18.3 MB/s eta 0:00:00
Downloading proto_plus-1.22.3-py3-none-any.whl (48 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 48.1/48.1 kB 6.1 MB/s eta 0:00:00
Downloading pyasn1-0.5.0-py2.py3-none-any.whl (83 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 83.9/83.9 kB 10.4 MB/s eta 0:00:00
Downloading pyasn1_modules-0.3.0-py2.py3-none-any.whl (181 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 181.3/181.3 kB 12.4 MB/s eta 0:00:00
Downloading pyparsing-3.1.1-py3-none-any.whl (103 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 103.1/103.1 kB 13.8 MB/s eta 0:00:00
Downloading requests-2.31.0-py3-none-any.whl (62 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 62.6/62.6 kB 8.2 MB/s eta 0:00:00
Downloading requests_oauthlib-1.3.1-py2.py3-none-any.whl (23 kB)
Downloading rsa-4.9-py3-none-any.whl (34 kB)
Downloading uritemplate-3.0.1-py2.py3-none-any.whl (15 kB)
Downloading urllib3-1.26.16-py2.py3-none-any.whl (143 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 143.1/143.1 kB 18.8 MB/s eta 0:00:00
Downloading websocket_client-1.6.2-py3-none-any.whl (57 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 57.0/57.0 kB 8.1 MB/s eta 0:00:00
Installing collected packages: websocket-client, urllib3, uritemplate, typing_extensions, six, PyYAML, pyparsing, Pygments, pyasn1, protobuf, packaging, oauthlib, MarkupSafe, idna, grpcio, charset-normalizer, certifi, cachetools, xds-protos, tenacity, rsa, requests, python-dateutil, pyasn1-modules, proto-plus, Mako, httplib2, grpcio-tools, grpcio-health-checking, grpcio-channelz, googleapis-common-protos, absl-py, requests-oauthlib, grpcio-status, google-auth, kubernetes, grpc-google-iam-v1, google-auth-httplib2, google-api-core, google-api-python-client, google-cloud-secret-manager, google-cloud-monitoring
Successfully installed Mako-1.2.4 MarkupSafe-2.1.3 PyYAML-6.0 Pygments-2.14.0 absl-py-0.15.0 cachetools-5.3.1 certifi-2023.7.22 charset-normalizer-3.2.0 google-api-core-2.11.1 google-api-python-client-1.12.11 google-auth-2.22.0 google-auth-httplib2-0.1.0 google-cloud-monitoring-2.18.0 google-cloud-secret-manager-2.15.1 googleapis-common-protos-1.60.0 grpc-google-iam-v1-0.12.6 grpcio-1.60.1 grpcio-channelz-1.60.1 grpcio-health-checking-1.60.1 grpcio-status-1.60.1 grpcio-tools-1.60.1 httplib2-0.22.0 idna-3.4 kubernetes-27.2.0 oauthlib-3.2.2 packaging-23.1 proto-plus-1.22.3 protobuf-4.24.1 pyasn1-0.5.0 pyasn1-modules-0.3.0 pyparsing-3.1.1 python-dateutil-2.8.2 requests-2.31.0 requests-oauthlib-1.3.1 rsa-4.9 six-1.16.0 tenacity-6.3.1 typing_extensions-4.10.0 uritemplate-3.0.1 urllib3-1.26.16 websocket-client-1.6.2 xds-protos-1.58.0rc1
Installed Python packages:
Package Version
--------------------------- ---------
absl-py 0.15.0
cachetools 5.3.1
certifi 2023.7.22
charset-normalizer 3.2.0
google-api-core 2.11.1
google-api-python-client 1.12.11
google-auth 2.22.0
google-auth-httplib2 0.1.0
google-cloud-monitoring 2.18.0
google-cloud-secret-manager 2.15.1
googleapis-common-protos 1.60.0
grpc-google-iam-v1 0.12.6
grpcio 1.60.1
grpcio-channelz 1.60.1
grpcio-health-checking 1.60.1
grpcio-status 1.60.1
grpcio-tools 1.60.1
httplib2 0.22.0
idna 3.4
kubernetes 27.2.0
Mako 1.2.4
MarkupSafe 2.1.3
oauthlib 3.2.2
packaging 23.1
pip 24.0
proto-plus 1.22.3
protobuf 4.24.1
pyasn1 0.5.0
pyasn1-modules 0.3.0
Pygments 2.14.0
pyparsing 3.1.1
python-dateutil 2.8.2
PyYAML 6.0
requests 2.31.0
requests-oauthlib 1.3.1
rsa 4.9
setuptools 69.2.0
six 1.16.0
tenacity 6.3.1
typing_extensions 4.10.0
uritemplate 3.0.1
urllib3 1.26.16
websocket-client 1.6.2
xds-protos 1.58.0rc1
Generate python code from grpc.testing protos: protos/grpc/testing/test.proto protos/grpc/testing/messages.proto protos/grpc/testing/empty.proto
/tmp/tmp.pWnnYGt0vw/psm-interop/venv/lib/python3.10/site-packages/grpc_tools/protoc.py:21: DeprecationWarning: pkg_resources is deprecated as an API. See https://setuptools.pypa.io/en/latest/pkg_resources.html
import pkg_resources
Generated files /tmp/tmp.pWnnYGt0vw/psm-interop/protos/grpc/testing:
total 108
-rw-rw-r-- 1 kbuilder kbuilder 957 Apr 4 16:12 empty.proto
-rw-rw-r-- 1 kbuilder kbuilder 1040 Apr 4 16:12 empty_pb2.py
-rw-rw-r-- 1 kbuilder kbuilder 159 Apr 4 16:12 empty_pb2_grpc.py
-rw-rw-r-- 1 kbuilder kbuilder 11527 Apr 4 16:12 messages.proto
-rw-rw-r-- 1 kbuilder kbuilder 17599 Apr 4 16:12 messages_pb2.py
-rw-rw-r-- 1 kbuilder kbuilder 159 Apr 4 16:12 messages_pb2_grpc.py
-rw-rw-r-- 1 kbuilder kbuilder 4871 Apr 4 16:12 test.proto
-rw-rw-r-- 1 kbuilder kbuilder 4353 Apr 4 16:12 test_pb2.py
-rw-rw-r-- 1 kbuilder kbuilder 41870 Apr 4 16:12 test_pb2_grpc.py
Server image: gcr.io/grpc-testing/xds-interop/cpp-server:64414d1b02f2038faec425523994a93ba4bcbe03
┌──────────────────────────────────────────┬──────────────┬─────────────────────┐
│ TAGS │ DIGEST │ TIMESTAMP │
├──────────────────────────────────────────┼──────────────┼─────────────────────┤
│ 64414d1b02f2038faec425523994a93ba4bcbe03 │ 2b4fd6611c9d │ 2024-04-03T23:56:13 │
└──────────────────────────────────────────┴──────────────┴─────────────────────┘
Client image: gcr.io/grpc-testing/xds-interop/python-client:64414d1b02f2038faec425523994a93ba4bcbe03
┌──────────────────────────────────────────┬──────────────┬─────────────────────┐
│ TAGS │ DIGEST │ TIMESTAMP │
├──────────────────────────────────────────┼──────────────┼─────────────────────┤
│ 64414d1b02f2038faec425523994a93ba4bcbe03 │ a5e2484582e7 │ 2024-04-03T23:49:40 │
└──────────────────────────────────────────┴──────────────┴─────────────────────┘
Skipping Python test app build
mkdir: created directory '/tmpfs/src/artifacts/grpc/core/master/linux/psm-csm-python/gamma.gamma_baseline_test'
+ python3 -m tests.gamma.gamma_baseline_test --flagfile=config/grpc-testing.cfg --flagfile=config/common-csm.cfg --kube_context=gke_grpc-testing_us-central1_psm-interop-csm --server_image=gcr.io/grpc-testing/xds-interop/cpp-server:64414d1b02f2038faec425523994a93ba4bcbe03 --client_image=gcr.io/grpc-testing/xds-interop/python-client:64414d1b02f2038faec425523994a93ba4bcbe03 --testing_version=dev-master --nocheck_local_certs --force_cleanup --collect_app_logs --log_dir=/tmpfs/src/artifacts/grpc/core/master/linux/psm-csm-python/gamma.gamma_baseline_test --xml_output_file=/tmpfs/src/artifacts/grpc/core/master/linux/psm-csm-python/gamma.gamma_baseline_test/sponge_log.xml
+ tee /tmpfs/src/artifacts/grpc/core/master/linux/psm-csm-python/gamma.gamma_baseline_test/sponge_log.log
Running tests under Python 3.10.12: /tmp/tmp.pWnnYGt0vw/psm-interop/venv/bin/python3
I0404 16:12:28.572780 139691982249984 xds_k8s_testcase.py:162] ----- Testing GammaBaselineTest -----
I0404 16:12:28.572942 139691982249984 xds_k8s_testcase.py:163] Logs timezone: UTC
I0404 16:12:28.573182 139691982249984 xds_k8s_testcase.py:111] Detected language and version: TestConfig(client_lang='python', server_lang='cpp', version='dev-master')
I0404 16:12:28.585116 139691982249984 k8s.py:243] Using kubernetes context "gke_grpc-testing_us-central1_psm-interop-csm", active host: https://34.29.103.132
[ RUN ] GammaBaselineTest.test_ping_pong
I0404 16:12:28.658907 139691982249984 xds_k8s_testcase.py:736] Test run resource prefix: psm-csm, suffix: 20240404-1612-vays5
I0404 16:12:29.041071 139691982249984 logs.py:31] Log root dir: /tmpfs/src/artifacts/grpc/core/master/linux/psm-csm-python/gamma.gamma_baseline_test
I0404 16:12:29.041760 139691982249984 xds_k8s_testcase.py:299] --- Starting subTest GammaBaselineTest.test_ping_pong.1_run_test_server ---
I0404 16:12:29.041880 139691982249984 gamma_server_runner.py:131] Deploying GAMMA xDS test server "psm-grpc-server" to k8s namespace psm-csm-server-20240404-1612-vays5: test_port=8080 maintenance_port=8080 secure_mode=False replica_count=1
I0404 16:12:29.042103 139691982249984 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-csm-server-20240404-1612-vays5%22;timeRange=2024-04-04T16:12:29.041944Z%2F2024-04-04T16:42:29.041944Z?project=grpc-testing
I0404 16:12:29.047975 139691982249984 k8s_base_runner.py:347] Rendered template kubernetes-manifests/namespace.yaml:
---
apiVersion: v1
kind: Namespace
metadata:
name: psm-csm-server-20240404-1612-vays5
labels:
name: psm-csm-server-20240404-1612-vays5
owner: xds-k8s-interop-test
...

I0404 16:12:29.098368 139691982249984 k8s_base_runner.py:367] Namespace psm-csm-server-20240404-1612-vays5 created
I0404 16:12:29.100914 139691982249984 k8s_base_runner.py:347] Rendered template kubernetes-manifests/gamma/service.yaml:
---
apiVersion: v1
kind: Service
metadata:
name: psm-grpc-server
namespace: psm-csm-server-20240404-1612-vays5
labels:
owner: xds-k8s-interop-test
spec:
type: ClusterIP
selector:
app: psm-grpc-server
ports:
- port: 8080
protocol: TCP
targetPort: 8080
...

I0404 16:12:29.250910 139691982249984 k8s_base_runner.py:367] Service psm-grpc-server created
I0404 16:12:29.252865 139691982249984 k8s_base_runner.py:347] Rendered template kubernetes-manifests/gamma/frontend_service.yaml:
---
apiVersion: v1
kind: Service
metadata:
name: psm-csm-20240404-1612-vays5
namespace: psm-csm-server-20240404-1612-vays5
labels:
owner: xds-k8s-interop-test
spec:
ports:
- port: 8080
targetPort: 8080

I0404 16:12:29.364281 139691982249984 k8s_base_runner.py:367] Service psm-csm-20240404-1612-vays5 created
I0404 16:12:29.366960 139691982249984 k8s_base_runner.py:347] Rendered template kubernetes-manifests/gamma/route_http.yaml:
---
kind: HTTPRoute
apiVersion: gateway.networking.k8s.io/v1beta1
metadata:
name: route-psm-grpc-server
namespace: psm-csm-server-20240404-1612-vays5
labels:
owner: xds-k8s-interop-test
spec:
parentRefs:
- name: psm-csm-20240404-1612-vays5
namespace: psm-csm-server-20240404-1612-vays5
group: ""
kind: Service
rules:
- matches:
- path:
type: Exact
value: /grpc.testing.TestService/UnaryCall
backendRefs:
- name: psm-grpc-server
port: 8080
...

I0404 16:12:29.415843 139691982249984 k8s_base_runner.py:367] HTTPRoute route-psm-grpc-server created
I0404 16:12:29.431253 139691982249984 k8s_base_runner.py:347] Rendered template kubernetes-manifests/server.deployment.yaml:
---
apiVersion: apps/v1
kind: Deployment
metadata:
name: psm-grpc-server
namespace: psm-csm-server-20240404-1612-vays5
labels:
app: psm-grpc-server
deployment_id: psm-grpc-server-oxbp4740
owner: xds-k8s-interop-test
spec:
replicas: 1
selector:
matchLabels:
app: psm-grpc-server
deployment_id: psm-grpc-server-oxbp4740
template:
metadata:
labels:
app: psm-grpc-server
deployment_id: psm-grpc-server-oxbp4740
owner: xds-k8s-interop-test
spec:
containers:
- name: psm-grpc-server
image: gcr.io/grpc-testing/xds-interop/cpp-server:64414d1b02f2038faec425523994a93ba4bcbe03
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: gcr.io/grpc-testing/td-grpc-bootstrap:2bf1b5ed00f852ffea8d24759c6fa673acc9ef10
imagePullPolicy: Always
args:
- "--output=/tmp/bootstrap/td-grpc-bootstrap.json"
- "--vpc-network-name=default-vpc"
- "--node-metadata=app=psm-csm-server-20240404-1612-vays5-psm-grpc-server"
- "--generate-mesh-id-experimental"
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

...

I0404 16:12:29.499395 139691982249984 k8s_base_runner.py:367] Deployment psm-grpc-server created
I0404 16:12:29.499585 139691982249984 k8s_base_runner.py:962] Waiting for deployment psm-grpc-server to initialize 1 pod(s)
I0404 16:12:30.605535 139691982249984 k8s_base_runner.py:972] Deployment psm-grpc-server initialized 1 pod(s): ['psm-grpc-server-5866945595-6kdz9']
I0404 16:12:30.605760 139691982249984 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-5866945595-6kdz9 to start
I0404 16:12:31.694121 139691982249984 k8s_base_runner.py:985] Pod psm-grpc-server-5866945595-6kdz9 ready, IP: 10.56.0.158
I0404 16:12:31.694339 139691982249984 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-5866945595-6kdz9 to gamma.gamma_baseline_test/test_app_logs/psm-csm-server-20240404-1612-vays5_psm-grpc-server-5866945595-6kdz9.log
I0404 16:12:31.694806 139691885585984 k8s_log_collector.py:71] [ns/psm-csm-server-20240404-1612-vays5] Starting log collection thread 139691885585984 for psm-grpc-server-5866945595-6kdz9
I0404 16:12:31.694992 139691982249984 k8s_base_runner.py:944] Waiting for deployment psm-grpc-server to report 1 available replica(s)
I0404 16:12:33.771324 139691982249984 k8s_base_runner.py:953] Deployment psm-grpc-server has 1 replicas available
I0404 16:12:33.771563 139691982249984 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-csm-server-20240404-1612-vays5
I0404 16:12:36.855773 139691982249984 k8s_base_runner.py:1068] Detected 'cloud.google.com/neg-status' annotation for Kubernetes Service psm-grpc-server, namespace psm-csm-server-20240404-1612-vays5: neg_name=k8s1-58b57ac6-psm-csm-server-20240404-1-psm-grpc-se-80-5bf33be1, port=8080, zones=['us-central1-a', 'us-central1-c']
I0404 16:12:36.855952 139691982249984 xds_k8s_testcase.py:304] --- Finished subTest GammaBaselineTest.test_ping_pong.1_run_test_server ---
I0404 16:12:36.856014 139691982249984 xds_k8s_testcase.py:299] --- Starting subTest GammaBaselineTest.test_ping_pong.2_start_test_client ---
I0404 16:12:36.856092 139691982249984 k8s_xds_client_runner.py:119] Deploying xDS test client "psm-grpc-client" to k8s namespace psm-csm-client-20240404-1612-vays5: server_target=xds:///psm-csm-20240404-1612-vays5.psm-csm-server-20240404-1612-vays5.svc.cluster.local:8080 rpc=UnaryCall qps=25 metadata='' secure_mode=False print_response=False
I0404 16:12:36.856274 139691982249984 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-csm-client-20240404-1612-vays5%22;timeRange=2024-04-04T16:12:36.856168Z%2F2024-04-04T16:42:36.856168Z?project=grpc-testing
I0404 16:12:36.858119 139691982249984 k8s_base_runner.py:347] Rendered template kubernetes-manifests/namespace.yaml:
---
apiVersion: v1
kind: Namespace
metadata:
name: psm-csm-client-20240404-1612-vays5
labels:
name: psm-csm-client-20240404-1612-vays5
owner: xds-k8s-interop-test
...

I0404 16:12:36.889748 139691982249984 k8s_base_runner.py:367] Namespace psm-csm-client-20240404-1612-vays5 created
I0404 16:12:36.899263 139691982249984 k8s_base_runner.py:347] Rendered template kubernetes-manifests/client.deployment.yaml:
---
apiVersion: apps/v1
kind: Deployment
metadata:
name: psm-grpc-client
namespace: psm-csm-client-20240404-1612-vays5
labels:
app: psm-grpc-client
deployment_id: psm-grpc-client-dznmy1aa
owner: xds-k8s-interop-test
spec:
replicas: 1
selector:
matchLabels:
app: psm-grpc-client
deployment_id: psm-grpc-client-dznmy1aa
template:
metadata:
labels:
app: psm-grpc-client
deployment_id: psm-grpc-client-dznmy1aa
owner: xds-k8s-interop-test
spec:
containers:
- name: psm-grpc-client
image: gcr.io/grpc-testing/xds-interop/python-client:64414d1b02f2038faec425523994a93ba4bcbe03
imagePullPolicy: Always
startupProbe:
tcpSocket:
port: 8079
periodSeconds: 3
failureThreshold: 1000
args:
- "--server=xds:///psm-csm-20240404-1612-vays5.psm-csm-server-20240404-1612-vays5.svc.cluster.local:8080"
- "--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: gcr.io/grpc-testing/td-grpc-bootstrap:2bf1b5ed00f852ffea8d24759c6fa673acc9ef10
imagePullPolicy: Always
args:
- "--output=/tmp/bootstrap/td-grpc-bootstrap.json"
- "--vpc-network-name=default-vpc"
- "--generate-mesh-id-experimental"
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
...

I0404 16:12:36.961097 139691982249984 k8s_base_runner.py:367] Deployment psm-grpc-client created
I0404 16:12:36.961287 139691982249984 k8s_base_runner.py:962] Waiting for deployment psm-grpc-client to initialize 1 pod(s)
I0404 16:12:38.038355 139691982249984 k8s_base_runner.py:972] Deployment psm-grpc-client initialized 1 pod(s): ['psm-grpc-client-644b6fcd78-tl7zs']
I0404 16:12:38.038588 139691982249984 k8s_base_runner.py:982] Waiting for pod psm-grpc-client-644b6fcd78-tl7zs to start
I0404 16:12:44.208063 139691982249984 k8s_base_runner.py:985] Pod psm-grpc-client-644b6fcd78-tl7zs ready, IP: 10.56.3.162
I0404 16:12:44.208273 139691982249984 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-client-644b6fcd78-tl7zs to gamma.gamma_baseline_test/test_app_logs/psm-csm-client-20240404-1612-vays5_psm-grpc-client-644b6fcd78-tl7zs.log
I0404 16:12:44.208649 139691877193280 k8s_log_collector.py:71] [ns/psm-csm-client-20240404-1612-vays5] Starting log collection thread 139691877193280 for psm-grpc-client-644b6fcd78-tl7zs
I0404 16:12:44.208796 139691982249984 k8s_base_runner.py:944] Waiting for deployment psm-grpc-client to report 1 available replica(s)
I0404 16:12:47.332051 139691982249984 k8s_base_runner.py:953] Deployment psm-grpc-client has 1 replicas available
I0404 16:12:47.332466 139691982249984 client_app.py:292] [psm-grpc-client-644b6fcd78-tl7zs] ADS: Waiting for active calls to xDS control plane to trafficdirector.googleapis.com:443
I0404 16:12:47.357484 139691982249984 client_app.py:320] [psm-grpc-client-644b6fcd78-tl7zs] xDS control plane channel:
I0404 16:12:57.377455 139691982249984 client_app.py:320] [psm-grpc-client-644b6fcd78-tl7zs] xDS control plane channel:
I0404 16:13:07.398134 139691982249984 client_app.py:320] [psm-grpc-client-644b6fcd78-tl7zs] xDS control plane channel:
I0404 16:13:17.417672 139691982249984 client_app.py:320] [psm-grpc-client-644b6fcd78-tl7zs] xDS control plane channel:
I0404 16:13:27.437118 139691982249984 client_app.py:320] [psm-grpc-client-644b6fcd78-tl7zs] xDS control plane channel:
I0404 16:13:43.463016 139691982249984 client_app.py:320] [psm-grpc-client-644b6fcd78-tl7zs] xDS control plane channel:
I0404 16:14:08.498520 139691982249984 client_app.py:320] [psm-grpc-client-644b6fcd78-tl7zs] xDS control plane channel:
I0404 16:14:10.506583 139691982249984 client_app.py:331] [psm-grpc-client-644b6fcd78-tl7zs] Detected active calls to xDS control plane trafficdirector.googleapis.com:443, channel:
I0404 16:14:10.506837 139691982249984 client_app.py:302] [psm-grpc-client-644b6fcd78-tl7zs] ADS: Detected active calls to xDS control plane trafficdirector.googleapis.com:443
I0404 16:14:10.507125 139691982249984 client_app.py:252] [psm-grpc-client-644b6fcd78-tl7zs] Waiting to report a READY channel to xds:///psm-csm-20240404-1612-vays5.psm-csm-server-20240404-1612-vays5.svc.cluster.local:8080
I0404 16:14:10.514907 139691982249984 client_app.py:379] [psm-grpc-client-644b6fcd78-tl7zs] Server channel:
I0404 16:14:10.515087 139691982249984 client_app.py:379] [psm-grpc-client-644b6fcd78-tl7zs] Server channel:
I0404 16:14:20.532522 139691982249984 client_app.py:379] [psm-grpc-client-644b6fcd78-tl7zs] Server channel:
I0404 16:14:20.532720 139691982249984 client_app.py:379] [psm-grpc-client-644b6fcd78-tl7zs] Server channel:
I0404 16:14:30.552386 139691982249984 client_app.py:379] [psm-grpc-client-644b6fcd78-tl7zs] Server channel:
I0404 16:14:30.552565 139691982249984 client_app.py:379] [psm-grpc-client-644b6fcd78-tl7zs] Server channel:
I0404 16:14:40.572764 139691982249984 client_app.py:379] [psm-grpc-client-644b6fcd78-tl7zs] Server channel:
I0404 16:14:40.572971 139691982249984 client_app.py:379] [psm-grpc-client-644b6fcd78-tl7zs] Server channel:
I0404 16:14:50.593634 139691982249984 client_app.py:379] [psm-grpc-client-644b6fcd78-tl7zs] Server channel:
I0404 16:14:50.593830 139691982249984 client_app.py:379] [psm-grpc-client-644b6fcd78-tl7zs] Server channel:
I0404 16:15:06.619729 139691982249984 client_app.py:379] [psm-grpc-client-644b6fcd78-tl7zs] Server channel:
I0404 16:15:06.619934 139691982249984 client_app.py:379] [psm-grpc-client-644b6fcd78-tl7zs] Server channel:
I0404 16:15:31.657242 139691982249984 client_app.py:379] [psm-grpc-client-644b6fcd78-tl7zs] Server channel:
I0404 16:15:31.661362 139691982249984 client_app.py:392] [psm-grpc-client-644b6fcd78-tl7zs] Found subchannel in state READY:
I0404 16:15:31.661617 139691982249984 client_app.py:263] [psm-grpc-client-644b6fcd78-tl7zs] Channel to xds:///psm-csm-20240404-1612-vays5.psm-csm-server-20240404-1612-vays5.svc.cluster.local:8080 transitioned to state READY:
I0404 16:15:31.661748 139691982249984 xds_k8s_testcase.py:304] --- Finished subTest GammaBaselineTest.test_ping_pong.2_start_test_client ---
I0404 16:15:31.661813 139691982249984 xds_k8s_testcase.py:299] --- Starting subTest GammaBaselineTest.test_ping_pong.3_test_server_received_rpcs_from_test_client ---
I0404 16:15:31.662063 139691982249984 grpc.py:75] [psm-grpc-client-644b6fcd78-tl7zs:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 100, 'timeoutSec': 1200}), timeout=1200, wait_for_ready=True)
I0404 16:15:35.736409 139691982249984 xds_k8s_testcase.py:669] [psm-grpc-client-644b6fcd78-tl7zs] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-5866945595-6kdz9: 100
rpcs_by_method:
UnaryCall:
psm-grpc-server-5866945595-6kdz9: 100

I0404 16:15:35.736632 139691982249984 xds_k8s_testcase.py:304] --- Finished subTest GammaBaselineTest.test_ping_pong.3_test_server_received_rpcs_from_test_client ---
I0404 16:15:35.736720 139691982249984 xds_k8s_testcase.py:755] ----- TestMethod GammaBaselineTest.test_ping_pong teardown -----
I0404 16:15:35.848478 139691982249984 k8s_base_runner.py:873] Deleting deployment psm-grpc-client
I0404 16:15:45.979104 139691982249984 k8s_base_runner.py:888] Deployment psm-grpc-client deleted
I0404 16:15:45.979341 139691982249984 k8s_base_runner.py:924] Deleting namespace psm-csm-client-20240404-1612-vays5
I0404 16:16:16.095614 139691982249984 k8s_base_runner.py:941] Namespace psm-csm-client-20240404-1612-vays5 deleted
I0404 16:16:16.095827 139691982249984 k8s_base_runner.py:779] Deleting HTTPRoute route-psm-grpc-server
I0404 16:16:17.219263 139691982249984 k8s_base_runner.py:793] HTTPRoute route-psm-grpc-server deleted
I0404 16:16:17.219435 139691982249984 k8s_base_runner.py:891] Deleting service psm-csm-20240404-1612-vays5
I0404 16:16:18.307558 139691982249984 k8s_base_runner.py:904] Service psm-csm-20240404-1612-vays5 deleted
I0404 16:16:18.307762 139691982249984 k8s_base_runner.py:891] Deleting service psm-grpc-server
I0404 16:16:19.432304 139691982249984 k8s_base_runner.py:904] Service psm-grpc-server deleted
I0404 16:16:19.432477 139691982249984 k8s_base_runner.py:873] Deleting deployment psm-grpc-server
I0404 16:16:29.537203 139691982249984 k8s_base_runner.py:888] Deployment psm-grpc-server deleted
I0404 16:16:29.537432 139691982249984 k8s_base_runner.py:796] Deleting GCPSessionAffinityPolicy ssa-policy
I0404 16:16:29.569946 139691982249984 k8s_base_runner.py:819] Deleting GCPSessionAffinityFilter ssa-filter
I0404 16:16:29.601608 139691982249984 k8s_base_runner.py:856] Deleting GCPBackendPolicy backend-policy
I0404 16:16:29.631414 139691982249984 k8s_base_runner.py:924] Deleting namespace psm-csm-server-20240404-1612-vays5
I0404 16:20:00.074071 139691982249984 k8s_base_runner.py:941] Namespace psm-csm-server-20240404-1612-vays5 deleted
I0404 16:20:00.074584 139691982249984 xds_k8s_testcase.py:779] ----- Test client/server logs -----
I0404 16:20:00.074850 139691982249984 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-client-dznmy1aa:
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-csm-client-20240404-1612-vays5%22%0Alabels.%22k8s-pod%2Fdeployment_id%22%3D%22psm-grpc-client-dznmy1aa%22;timeRange=2024-04-04T16:12:36.856163Z%2F2024-04-04T16:16:16.095791Z;cursorTimestamp=2024-04-04T16:12:47.332259Z?project=grpc-testing
I0404 16:20:00.075084 139691982249984 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-server-oxbp4740:
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-csm-server-20240404-1612-vays5%22%0Alabels.%22k8s-pod%2Fdeployment_id%22%3D%22psm-grpc-server-oxbp4740%22;timeRange=2024-04-04T16:12:29.041939Z%2F2024-04-04T16:20:00.074312Z;cursorTimestamp=2024-04-04T16:12:33.771509Z?project=grpc-testing
[ OK ] GammaBaselineTest.test_ping_pong
I0404 16:20:00.075477 139691982249984 base_testcase.py:67] ----- PSM Test Case PASSED: GammaBaselineTest.test_ping_pong -----

----------------------------------------------------------------------
Ran 1 test in 451.503s

OK
+ set +x
mkdir: created directory '/tmpfs/src/artifacts/grpc/core/master/linux/psm-csm-python/gamma.affinity_session_drain_test'
+ python3 -m tests.gamma.affinity_session_drain_test --flagfile=config/grpc-testing.cfg --flagfile=config/common-csm.cfg --kube_context=gke_grpc-testing_us-central1_psm-interop-csm --server_image=gcr.io/grpc-testing/xds-interop/cpp-server:64414d1b02f2038faec425523994a93ba4bcbe03 --client_image=gcr.io/grpc-testing/xds-interop/python-client:64414d1b02f2038faec425523994a93ba4bcbe03 --testing_version=dev-master --nocheck_local_certs --force_cleanup --collect_app_logs --log_dir=/tmpfs/src/artifacts/grpc/core/master/linux/psm-csm-python/gamma.affinity_session_drain_test --xml_output_file=/tmpfs/src/artifacts/grpc/core/master/linux/psm-csm-python/gamma.affinity_session_drain_test/sponge_log.xml
+ tee /tmpfs/src/artifacts/grpc/core/master/linux/psm-csm-python/gamma.affinity_session_drain_test/sponge_log.log
Running tests under Python 3.10.12: /tmp/tmp.pWnnYGt0vw/psm-interop/venv/bin/python3
I0404 16:20:01.665289 140443674669056 xds_k8s_testcase.py:162] ----- Testing AffinitySessionDrainTest -----
I0404 16:20:01.665460 140443674669056 xds_k8s_testcase.py:163] Logs timezone: UTC
I0404 16:20:01.665712 140443674669056 xds_k8s_testcase.py:111] Detected language and version: TestConfig(client_lang='python', server_lang='cpp', version='dev-master')
I0404 16:20:01.678363 140443674669056 k8s.py:243] Using kubernetes context "gke_grpc-testing_us-central1_psm-interop-csm", active host: https://34.29.103.132
[ RUN ] AffinitySessionDrainTest.test_session_drain
I0404 16:20:01.684247 140443674669056 xds_k8s_testcase.py:736] Test run resource prefix: psm-csm, suffix: 20240404-1620-7bkd7
I0404 16:20:02.041062 140443674669056 logs.py:31] Log root dir: /tmpfs/src/artifacts/grpc/core/master/linux/psm-csm-python/gamma.affinity_session_drain_test
I0404 16:20:02.041776 140443674669056 xds_k8s_testcase.py:299] --- Starting subTest AffinitySessionDrainTest.test_session_drain.01_run_test_server ---
I0404 16:20:02.041898 140443674669056 gamma_server_runner.py:131] Deploying GAMMA xDS test server "psm-grpc-server" to k8s namespace psm-csm-server-20240404-1620-7bkd7: test_port=8080 maintenance_port=8080 secure_mode=False replica_count=3
I0404 16:20:02.042127 140443674669056 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-csm-server-20240404-1620-7bkd7%22;timeRange=2024-04-04T16:20:02.041974Z%2F2024-04-04T16:50:02.041974Z?project=grpc-testing
I0404 16:20:02.047258 140443674669056 k8s_base_runner.py:347] Rendered template kubernetes-manifests/namespace.yaml:
---
apiVersion: v1
kind: Namespace
metadata:
name: psm-csm-server-20240404-1620-7bkd7
labels:
name: psm-csm-server-20240404-1620-7bkd7
owner: xds-k8s-interop-test
...

I0404 16:20:02.124632 140443674669056 k8s_base_runner.py:367] Namespace psm-csm-server-20240404-1620-7bkd7 created
I0404 16:20:02.127312 140443674669056 k8s_base_runner.py:347] Rendered template kubernetes-manifests/gamma/service.yaml:
---
apiVersion: v1
kind: Service
metadata:
name: psm-grpc-server
namespace: psm-csm-server-20240404-1620-7bkd7
labels:
owner: xds-k8s-interop-test
spec:
type: ClusterIP
selector:
app: psm-grpc-server
ports:
- port: 8080
protocol: TCP
targetPort: 8080
...

I0404 16:20:02.234171 140443674669056 k8s_base_runner.py:367] Service psm-grpc-server created
I0404 16:20:02.236193 140443674669056 k8s_base_runner.py:347] Rendered template kubernetes-manifests/gamma/frontend_service.yaml:
---
apiVersion: v1
kind: Service
metadata:
name: psm-csm-20240404-1620-7bkd7
namespace: psm-csm-server-20240404-1620-7bkd7
labels:
owner: xds-k8s-interop-test
spec:
ports:
- port: 8080
targetPort: 8080

I0404 16:20:02.309598 140443674669056 k8s_base_runner.py:367] Service psm-csm-20240404-1620-7bkd7 created
I0404 16:20:02.312628 140443674669056 k8s_base_runner.py:347] Rendered template kubernetes-manifests/gamma/route_http.yaml:
---
kind: HTTPRoute
apiVersion: gateway.networking.k8s.io/v1beta1
metadata:
name: route-psm-grpc-server
namespace: psm-csm-server-20240404-1620-7bkd7
labels:
owner: xds-k8s-interop-test
spec:
parentRefs:
- name: psm-csm-20240404-1620-7bkd7
namespace: psm-csm-server-20240404-1620-7bkd7
group: ""
kind: Service
rules:
- matches:
- path:
type: Exact
value: /grpc.testing.TestService/UnaryCall
backendRefs:
- name: psm-grpc-server
port: 8080
...

I0404 16:20:02.365385 140443674669056 k8s_base_runner.py:367] HTTPRoute route-psm-grpc-server created
I0404 16:20:02.448206 140443674669056 k8s_base_runner.py:347] Rendered template kubernetes-manifests/server.deployment.yaml:
---
apiVersion: apps/v1
kind: Deployment
metadata:
name: psm-grpc-server
namespace: psm-csm-server-20240404-1620-7bkd7
labels:
app: psm-grpc-server
deployment_id: psm-grpc-server-jib1mvk4
owner: xds-k8s-interop-test
spec:
replicas: 3
selector:
matchLabels:
app: psm-grpc-server
deployment_id: psm-grpc-server-jib1mvk4
template:
metadata:
labels:
app: psm-grpc-server
deployment_id: psm-grpc-server-jib1mvk4
owner: xds-k8s-interop-test
spec:
containers:
- name: psm-grpc-server
image: gcr.io/grpc-testing/xds-interop/cpp-server:64414d1b02f2038faec425523994a93ba4bcbe03
imagePullPolicy: Always
startupProbe:
tcpSocket:
port: 8080
periodSeconds: 3
failureThreshold: 1000
lifecycle:
preStop:
exec:
command:
- "/tmp/prestop-hook/grpcurl"
- "-vv"
- "--plaintext"
- "--import-path=/tmp/prestop-hook"
- "--proto=/tmp/prestop-hook/protos/grpc/testing/test.proto"
- "localhost:8080"
- "grpc.testing.HookService/Hook"
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
- name: prestop-hook-volume
mountPath: /tmp/prestop-hook
resources:
limits:
cpu: 800m
memory: 512Mi
requests:
cpu: 100m
memory: 512Mi
initContainers:
- name: grpc-td-init
image: gcr.io/grpc-testing/td-grpc-bootstrap:2bf1b5ed00f852ffea8d24759c6fa673acc9ef10
imagePullPolicy: Always
args:
- "--output=/tmp/bootstrap/td-grpc-bootstrap.json"
- "--vpc-network-name=default-vpc"
- "--node-metadata=app=psm-csm-server-20240404-1620-7bkd7-psm-grpc-server"
- "--generate-mesh-id-experimental"
resources:
limits:
cpu: 100m
memory: 100Mi
requests:
cpu: 10m
memory: 100Mi
volumeMounts:
- mountPath: /tmp/bootstrap/
name: grpc-td-conf
- name: prestop-hook-init
image: gcr.io/grpc-testing/xds-interop/prestop-hook:v0.0.6
imagePullPolicy: Always
args: ["/tmp/prestop-hook"]
resources:
limits:
cpu: 100m
memory: 100Mi
requests:
cpu: 10m
memory: 100Mi
volumeMounts:
- name: prestop-hook-volume
mountPath: /tmp/prestop-hook
volumes:
- name: grpc-td-conf
emptyDir:
medium: Memory
- name: prestop-hook-volume
emptyDir:
medium: Memory
...

I0404 16:20:02.520601 140443674669056 k8s_base_runner.py:367] Deployment psm-grpc-server created
I0404 16:20:02.520798 140443674669056 k8s_base_runner.py:962] Waiting for deployment psm-grpc-server to initialize 3 pod(s)
I0404 16:20:03.625607 140443674669056 k8s_base_runner.py:972] Deployment psm-grpc-server initialized 3 pod(s): ['psm-grpc-server-5d47686f44-4khxw', 'psm-grpc-server-5d47686f44-69t5p', 'psm-grpc-server-5d47686f44-m75pb']
I0404 16:20:03.625972 140443674669056 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-5d47686f44-4khxw to start
I0404 16:20:06.764144 140443674669056 k8s_base_runner.py:985] Pod psm-grpc-server-5d47686f44-4khxw ready, IP: 10.56.3.163
I0404 16:20:06.764359 140443674669056 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-5d47686f44-4khxw to gamma.affinity_session_drain_test/test_app_logs/psm-csm-server-20240404-1620-7bkd7_psm-grpc-server-5d47686f44-4khxw.log
I0404 16:20:06.764778 140443578263104 k8s_log_collector.py:71] [ns/psm-csm-server-20240404-1620-7bkd7] Starting log collection thread 140443578263104 for psm-grpc-server-5d47686f44-4khxw
I0404 16:20:06.764991 140443674669056 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-5d47686f44-69t5p to start
I0404 16:20:06.817893 140443674669056 k8s_base_runner.py:985] Pod psm-grpc-server-5d47686f44-69t5p ready, IP: 10.56.0.159
I0404 16:20:06.818100 140443674669056 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-5d47686f44-69t5p to gamma.affinity_session_drain_test/test_app_logs/psm-csm-server-20240404-1620-7bkd7_psm-grpc-server-5d47686f44-69t5p.log
I0404 16:20:06.818555 140443569870400 k8s_log_collector.py:71] [ns/psm-csm-server-20240404-1620-7bkd7] Starting log collection thread 140443569870400 for psm-grpc-server-5d47686f44-69t5p
I0404 16:20:06.818749 140443674669056 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-5d47686f44-m75pb to start
I0404 16:20:07.892547 140443674669056 k8s_base_runner.py:985] Pod psm-grpc-server-5d47686f44-m75pb ready, IP: 10.56.4.116
I0404 16:20:07.892770 140443674669056 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-5d47686f44-m75pb to gamma.affinity_session_drain_test/test_app_logs/psm-csm-server-20240404-1620-7bkd7_psm-grpc-server-5d47686f44-m75pb.log
I0404 16:20:07.893177 140443560429120 k8s_log_collector.py:71] [ns/psm-csm-server-20240404-1620-7bkd7] Starting log collection thread 140443560429120 for psm-grpc-server-5d47686f44-m75pb
I0404 16:20:07.893383 140443674669056 k8s_base_runner.py:944] Waiting for deployment psm-grpc-server to report 3 available replica(s)
I0404 16:20:09.964634 140443674669056 k8s_base_runner.py:953] Deployment psm-grpc-server has 3 replicas available
I0404 16:20:09.964911 140443674669056 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-csm-server-20240404-1620-7bkd7
I0404 16:20:10.012432 140443674669056 k8s_base_runner.py:1068] Detected 'cloud.google.com/neg-status' annotation for Kubernetes Service psm-grpc-server, namespace psm-csm-server-20240404-1620-7bkd7: neg_name=k8s1-58b57ac6-psm-csm-server-20240404-1-psm-grpc-se-80-75e47ff1, port=8080, zones=['us-central1-a', 'us-central1-c']
I0404 16:20:10.012655 140443674669056 xds_k8s_testcase.py:304] --- Finished subTest AffinitySessionDrainTest.test_session_drain.01_run_test_server ---
I0404 16:20:10.012742 140443674669056 xds_k8s_testcase.py:299] --- Starting subTest AffinitySessionDrainTest.test_session_drain.02_create_ssa_policies ---
I0404 16:20:10.015080 140443674669056 k8s_base_runner.py:347] Rendered template kubernetes-manifests/gamma/session_affinity_policy_route.yaml:
---
apiVersion: networking.gke.io/v1
kind: GCPSessionAffinityPolicy
metadata:
name: ssa-policy
namespace: psm-csm-server-20240404-1620-7bkd7
labels:
owner: xds-k8s-interop-test
spec:
statefulGeneratedCookie:
cookieTtlSeconds: 50
targetRef:
name: route-psm-grpc-server
group: gateway.networking.k8s.io
kind: HTTPRoute
namespace: psm-csm-server-20240404-1620-7bkd7
...

I0404 16:20:10.058104 140443674669056 k8s_base_runner.py:367] GCPSessionAffinityPolicy ssa-policy created
I0404 16:20:10.061013 140443674669056 k8s_base_runner.py:347] Rendered template kubernetes-manifests/gamma/backend_policy.yaml:
---
kind: GCPBackendPolicy
apiVersion: networking.gke.io/v1
metadata:
name: backend-policy
namespace: psm-csm-server-20240404-1620-7bkd7
labels:
owner: xds-k8s-interop-test
spec:
targetRef:
group: ""
kind: Service
name: psm-grpc-server
default:
connectionDraining:
drainingTimeoutSec: 600
...

I0404 16:20:10.159372 140443674669056 k8s_base_runner.py:367] GCPBackendPolicy backend-policy created
I0404 16:20:10.159578 140443674669056 xds_k8s_testcase.py:304] --- Finished subTest AffinitySessionDrainTest.test_session_drain.02_create_ssa_policies ---
I0404 16:20:10.159647 140443674669056 xds_k8s_testcase.py:299] --- Starting subTest AffinitySessionDrainTest.test_session_drain.03_start_test_client ---
I0404 16:20:10.159732 140443674669056 k8s_xds_client_runner.py:119] Deploying xDS test client "psm-grpc-client" to k8s namespace psm-csm-client-20240404-1620-7bkd7: server_target=xds:///psm-csm-20240404-1620-7bkd7.psm-csm-server-20240404-1620-7bkd7.svc.cluster.local:8080 rpc=UnaryCall qps=25 metadata='' secure_mode=False print_response=False
I0404 16:20:10.159936 140443674669056 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-csm-client-20240404-1620-7bkd7%22;timeRange=2024-04-04T16:20:10.159821Z%2F2024-04-04T16:50:10.159821Z?project=grpc-testing
I0404 16:20:10.161742 140443674669056 k8s_base_runner.py:347] Rendered template kubernetes-manifests/namespace.yaml:
---
apiVersion: v1
kind: Namespace
metadata:
name: psm-csm-client-20240404-1620-7bkd7
labels:
name: psm-csm-client-20240404-1620-7bkd7
owner: xds-k8s-interop-test
...

I0404 16:20:10.183746 140443674669056 k8s_base_runner.py:367] Namespace psm-csm-client-20240404-1620-7bkd7 created
I0404 16:20:10.193373 140443674669056 k8s_base_runner.py:347] Rendered template kubernetes-manifests/client.deployment.yaml:
---
apiVersion: apps/v1
kind: Deployment
metadata:
name: psm-grpc-client
namespace: psm-csm-client-20240404-1620-7bkd7
labels:
app: psm-grpc-client
deployment_id: psm-grpc-client-aotw7wzl
owner: xds-k8s-interop-test
spec:
replicas: 1
selector:
matchLabels:
app: psm-grpc-client
deployment_id: psm-grpc-client-aotw7wzl
template:
metadata:
labels:
app: psm-grpc-client
deployment_id: psm-grpc-client-aotw7wzl
owner: xds-k8s-interop-test
spec:
containers:
- name: psm-grpc-client
image: gcr.io/grpc-testing/xds-interop/python-client:64414d1b02f2038faec425523994a93ba4bcbe03
imagePullPolicy: Always
startupProbe:
tcpSocket:
port: 8079
periodSeconds: 3
failureThreshold: 1000
args:
- "--server=xds:///psm-csm-20240404-1620-7bkd7.psm-csm-server-20240404-1620-7bkd7.svc.cluster.local:8080"
- "--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: gcr.io/grpc-testing/td-grpc-bootstrap:2bf1b5ed00f852ffea8d24759c6fa673acc9ef10
imagePullPolicy: Always
args:
- "--output=/tmp/bootstrap/td-grpc-bootstrap.json"
- "--vpc-network-name=default-vpc"
- "--generate-mesh-id-experimental"
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
...

I0404 16:20:10.272418 140443674669056 k8s_base_runner.py:367] Deployment psm-grpc-client created
I0404 16:20:10.272624 140443674669056 k8s_base_runner.py:962] Waiting for deployment psm-grpc-client to initialize 1 pod(s)
I0404 16:20:11.334988 140443674669056 k8s_base_runner.py:972] Deployment psm-grpc-client initialized 1 pod(s): ['psm-grpc-client-b94d5dbb4-4pc6r']
I0404 16:20:11.335217 140443674669056 k8s_base_runner.py:982] Waiting for pod psm-grpc-client-b94d5dbb4-4pc6r to start
I0404 16:20:13.413354 140443674669056 k8s_base_runner.py:985] Pod psm-grpc-client-b94d5dbb4-4pc6r ready, IP: 10.56.2.122
I0404 16:20:13.413575 140443674669056 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-client-b94d5dbb4-4pc6r to gamma.affinity_session_drain_test/test_app_logs/psm-csm-client-20240404-1620-7bkd7_psm-grpc-client-b94d5dbb4-4pc6r.log
I0404 16:20:13.414032 140443350201920 k8s_log_collector.py:71] [ns/psm-csm-client-20240404-1620-7bkd7] Starting log collection thread 140443350201920 for psm-grpc-client-b94d5dbb4-4pc6r
I0404 16:20:13.414228 140443674669056 k8s_base_runner.py:944] Waiting for deployment psm-grpc-client to report 1 available replica(s)
I0404 16:20:14.473722 140443674669056 k8s_base_runner.py:953] Deployment psm-grpc-client has 1 replicas available
I0404 16:20:14.474135 140443674669056 client_app.py:292] [psm-grpc-client-b94d5dbb4-4pc6r] ADS: Waiting for active calls to xDS control plane to trafficdirector.googleapis.com:443
I0404 16:20:14.502489 140443674669056 client_app.py:320] [psm-grpc-client-b94d5dbb4-4pc6r] xDS control plane channel:
I0404 16:20:24.521901 140443674669056 client_app.py:320] [psm-grpc-client-b94d5dbb4-4pc6r] xDS control plane channel:
I0404 16:20:34.542171 140443674669056 client_app.py:320] [psm-grpc-client-b94d5dbb4-4pc6r] xDS control plane channel:
I0404 16:20:44.561422 140443674669056 client_app.py:320] [psm-grpc-client-b94d5dbb4-4pc6r] xDS control plane channel:
I0404 16:20:54.580864 140443674669056 client_app.py:320] [psm-grpc-client-b94d5dbb4-4pc6r] xDS control plane channel:
I0404 16:21:10.606903 140443674669056 client_app.py:320] [psm-grpc-client-b94d5dbb4-4pc6r] xDS control plane channel:
I0404 16:21:35.644219 140443674669056 client_app.py:320] [psm-grpc-client-b94d5dbb4-4pc6r] xDS control plane channel:
I0404 16:21:37.652043 140443674669056 client_app.py:331] [psm-grpc-client-b94d5dbb4-4pc6r] Detected active calls to xDS control plane trafficdirector.googleapis.com:443, channel:
I0404 16:21:37.652281 140443674669056 client_app.py:302] [psm-grpc-client-b94d5dbb4-4pc6r] ADS: Detected active calls to xDS control plane trafficdirector.googleapis.com:443
I0404 16:21:37.652607 140443674669056 client_app.py:252] [psm-grpc-client-b94d5dbb4-4pc6r] Waiting to report a READY channel to xds:///psm-csm-20240404-1620-7bkd7.psm-csm-server-20240404-1620-7bkd7.svc.cluster.local:8080
I0404 16:21:37.660785 140443674669056 client_app.py:379] [psm-grpc-client-b94d5dbb4-4pc6r] Server channel:
I0404 16:21:37.660955 140443674669056 client_app.py:379] [psm-grpc-client-b94d5dbb4-4pc6r] Server channel:
I0404 16:21:47.683630 140443674669056 client_app.py:379] [psm-grpc-client-b94d5dbb4-4pc6r] Server channel:
I0404 16:21:47.683828 140443674669056 client_app.py:379] [psm-grpc-client-b94d5dbb4-4pc6r] Server channel:
I0404 16:21:57.704318 140443674669056 client_app.py:379] [psm-grpc-client-b94d5dbb4-4pc6r] Server channel:
I0404 16:21:57.704498 140443674669056 client_app.py:379] [psm-grpc-client-b94d5dbb4-4pc6r] Server channel:
I0404 16:22:07.719986 140443674669056 client_app.py:379] [psm-grpc-client-b94d5dbb4-4pc6r] Server channel:
I0404 16:22:07.720173 140443674669056 client_app.py:379] [psm-grpc-client-b94d5dbb4-4pc6r] Server channel:
I0404 16:22:17.737473 140443674669056 client_app.py:379] [psm-grpc-client-b94d5dbb4-4pc6r] Server channel:
I0404 16:22:17.741931 140443674669056 client_app.py:392] [psm-grpc-client-b94d5dbb4-4pc6r] Found subchannel in state READY:
I0404 16:22:17.742191 140443674669056 client_app.py:263] [psm-grpc-client-b94d5dbb4-4pc6r] Channel to xds:///psm-csm-20240404-1620-7bkd7.psm-csm-server-20240404-1620-7bkd7.svc.cluster.local:8080 transitioned to state READY:
I0404 16:22:17.742305 140443674669056 xds_k8s_testcase.py:304] --- Finished subTest AffinitySessionDrainTest.test_session_drain.03_start_test_client ---
I0404 16:22:17.742368 140443674669056 xds_k8s_testcase.py:299] --- Starting subTest AffinitySessionDrainTest.test_session_drain.04_confirm_all_servers_receive_traffic ---
I0404 16:22:17.742694 140443674669056 xds_k8s_testcase.py:506] Verifying RPCs go to servers ['psm-grpc-server-5d47686f44-4khxw', 'psm-grpc-server-5d47686f44-69t5p', 'psm-grpc-server-5d47686f44-m75pb']
I0404 16:22:17.742971 140443674669056 grpc.py:75] [psm-grpc-client-b94d5dbb4-4pc6r:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 120, 'timeoutSec': 1200, 'metadataKeys': ['set-cookie']}), timeout=1200, wait_for_ready=True)
I0404 16:22:22.633983 140443674669056 xds_k8s_testcase.py:669] [psm-grpc-client-b94d5dbb4-4pc6r] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-5d47686f44-4khxw: 120
rpcs_by_method:
UnaryCall:
psm-grpc-server-5d47686f44-4khxw: 120
metadatas_by_peer:
psm-grpc-server-5d47686f44-4khxw:
set-cookie:
- GSSA=MTAuNTYuMy4xNjM6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfMzEwNDExNjgzOTUxNTY0NzM5NQ==;
HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50

I0404 16:22:22.634687 140443674669056 retryers.py:213] Retrying framework.xds_k8s_testcase.XdsKubernetesBaseTestCase._assertRpcsEventuallyGoToGivenServers in 5.0 seconds as it raised AssertionError: 'psm-grpc-server-5d47686f44-69t5p' not found in {'psm-grpc-server-5d47686f44-4khxw': 120} : Server psm-grpc-server-5d47686f44-69t5p did not receive RPCs
I0404 16:22:27.639998 140443674669056 xds_k8s_testcase.py:506] Verifying RPCs go to servers ['psm-grpc-server-5d47686f44-4khxw', 'psm-grpc-server-5d47686f44-69t5p', 'psm-grpc-server-5d47686f44-m75pb']
I0404 16:22:27.640296 140443674669056 grpc.py:75] [psm-grpc-client-b94d5dbb4-4pc6r:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 120, 'timeoutSec': 1200, 'metadataKeys': ['set-cookie']}), timeout=1200, wait_for_ready=True)
I0404 16:22:32.525764 140443674669056 xds_k8s_testcase.py:669] [psm-grpc-client-b94d5dbb4-4pc6r] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-5d47686f44-4khxw: 120
rpcs_by_method:
UnaryCall:
psm-grpc-server-5d47686f44-4khxw: 120
metadatas_by_peer:
psm-grpc-server-5d47686f44-4khxw:
set-cookie:
- GSSA=MTAuNTYuMy4xNjM6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfMzEwNDExNjgzOTUxNTY0NzM5NQ==;
HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50

I0404 16:22:32.526070 140443674669056 retryers.py:213] Retrying framework.xds_k8s_testcase.XdsKubernetesBaseTestCase._assertRpcsEventuallyGoToGivenServers in 5.0 seconds as it raised AssertionError: 'psm-grpc-server-5d47686f44-69t5p' not found in {'psm-grpc-server-5d47686f44-4khxw': 120} : Server psm-grpc-server-5d47686f44-69t5p did not receive RPCs
I0404 16:22:37.531321 140443674669056 xds_k8s_testcase.py:506] Verifying RPCs go to servers ['psm-grpc-server-5d47686f44-4khxw', 'psm-grpc-server-5d47686f44-69t5p', 'psm-grpc-server-5d47686f44-m75pb']
I0404 16:22:37.531667 140443674669056 grpc.py:75] [psm-grpc-client-b94d5dbb4-4pc6r:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 120, 'timeoutSec': 1200, 'metadataKeys': ['set-cookie']}), timeout=1200, wait_for_ready=True)
I0404 16:22:42.421403 140443674669056 xds_k8s_testcase.py:669] [psm-grpc-client-b94d5dbb4-4pc6r] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-5d47686f44-4khxw: 39
psm-grpc-server-5d47686f44-m75pb: 40
psm-grpc-server-5d47686f44-69t5p: 41
rpcs_by_method:
UnaryCall:
psm-grpc-server-5d47686f44-4khxw: 39
psm-grpc-server-5d47686f44-m75pb: 40
psm-grpc-server-5d47686f44-69t5p: 41
metadatas_by_peer:
psm-grpc-server-5d47686f44-4khxw:
set-cookie:
- GSSA=MTAuNTYuMy4xNjM6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfMzEwNDExNjgzOTUxNTY0NzM5NQ==;
HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50
psm-grpc-server-5d47686f44-m75pb:
set-cookie:
- GSSA=MTAuNTYuNC4xMTY6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfMzEwNDExNjgzOTUxNTY0NzM5NQ==;
HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50
psm-grpc-server-5d47686f44-69t5p:
set-cookie:
- GSSA=MTAuNTYuMC4xNTk6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfMzEwNDExNjgzOTUxNTY0NzM5NQ==;
HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50

I0404 16:22:42.421701 140443674669056 affinity_session_drain_test.py:128] Confirmed all servers received traffic: ['psm-grpc-server-5d47686f44-4khxw', 'psm-grpc-server-5d47686f44-69t5p', 'psm-grpc-server-5d47686f44-m75pb']
I0404 16:22:42.421803 140443674669056 xds_k8s_testcase.py:304] --- Finished subTest AffinitySessionDrainTest.test_session_drain.04_confirm_all_servers_receive_traffic ---
I0404 16:22:42.421857 140443674669056 xds_k8s_testcase.py:299] --- Starting subTest AffinitySessionDrainTest.test_session_drain.05_retrieve_cookie ---
I0404 16:22:42.422189 140443674669056 grpc.py:75] [psm-grpc-client-b94d5dbb4-4pc6r:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 1, 'timeoutSec': 1200, 'metadataKeys': ['set-cookie']}), timeout=1200, wait_for_ready=True)
I0404 16:22:42.535639 140443674669056 xds_k8s_testcase.py:669] [psm-grpc-client-b94d5dbb4-4pc6r] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-5d47686f44-4khxw: 1
rpcs_by_method:
UnaryCall:
psm-grpc-server-5d47686f44-4khxw: 1
metadatas_by_peer:
psm-grpc-server-5d47686f44-4khxw:
set-cookie:
- GSSA=MTAuNTYuMy4xNjM6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfMzEwNDExNjgzOTUxNTY0NzM5NQ==;
HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50

I0404 16:22:42.536062 140443674669056 affinity_session_drain_test.py:139] Chosen server: psm-grpc-server-5d47686f44-4khxw, cookie: GSSA=MTAuNTYuMy4xNjM6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfMzEwNDExNjgzOTUxNTY0NzM5NQ==; HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50
I0404 16:22:42.536162 140443674669056 xds_k8s_testcase.py:304] --- Finished subTest AffinitySessionDrainTest.test_session_drain.05_retrieve_cookie ---
I0404 16:22:42.536222 140443674669056 xds_k8s_testcase.py:299] --- Starting subTest AffinitySessionDrainTest.test_session_drain.06_only_chosen_server_receives_rpcs_with_cookie ---
I0404 16:22:42.536267 140443674669056 affinity_session_drain_test.py:142] Configuring client to send cookie GSSA=MTAuNTYuMy4xNjM6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfMzEwNDExNjgzOTUxNTY0NzM5NQ==; HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50
I0404 16:22:42.536507 140443674669056 grpc.py:75] [psm-grpc-client-b94d5dbb4-4pc6r:8079] >> RPC XdsUpdateClientConfigureService.Configure(request=ClientConfigureRequest({'types': ['UNARY_CALL'], 'metadata': [{'type': 'UNARY_CALL', 'key': 'cookie', 'value': 'GSSA=MTAuNTYuMy4xNjM6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfMzEwNDExNjgzOTUxNTY0NzM5NQ==; HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50'}]}), wait_for_ready=True, timeout=5)
I0404 16:22:42.540425 140443674669056 xds_k8s_testcase.py:506] Verifying RPCs go to servers ['psm-grpc-server-5d47686f44-4khxw']
I0404 16:22:42.540676 140443674669056 grpc.py:75] [psm-grpc-client-b94d5dbb4-4pc6r:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 100, 'timeoutSec': 1200, 'metadataKeys': ['set-cookie']}), timeout=1200, wait_for_ready=True)
I0404 16:22:46.637967 140443674669056 xds_k8s_testcase.py:669] [psm-grpc-client-b94d5dbb4-4pc6r] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-5d47686f44-4khxw: 100
rpcs_by_method:
UnaryCall:
psm-grpc-server-5d47686f44-4khxw: 100

I0404 16:22:46.638327 140443674669056 affinity_session_drain_test.py:154] Confirmed all RPCs went to psm-grpc-server-5d47686f44-4khxw
I0404 16:22:46.638424 140443674669056 xds_k8s_testcase.py:304] --- Finished subTest AffinitySessionDrainTest.test_session_drain.06_only_chosen_server_receives_rpcs_with_cookie ---
I0404 16:22:46.638508 140443674669056 xds_k8s_testcase.py:299] --- Starting subTest AffinitySessionDrainTest.test_session_drain.07_stopping_chosen_server ---
I0404 16:22:46.638619 140443674669056 k8s_base_runner.py:527] [ns/psm-csm-server-20240404-1620-7bkd7] Deleting pod psm-grpc-server-5d47686f44-4khxw with 0:10:00 (h:mm:ss) grace period.
I0404 16:22:46.727848 140443674669056 k8s_base_runner.py:554] [ns/psm-csm-server-20240404-1620-7bkd7] Pod psm-grpc-server-5d47686f44-4khxw deleted with 0:10:00 (h:mm:ss) grace period.
I0404 16:22:46.728039 140443674669056 xds_k8s_testcase.py:304] --- Finished subTest AffinitySessionDrainTest.test_session_drain.07_stopping_chosen_server ---
I0404 16:22:46.728104 140443674669056 xds_k8s_testcase.py:299] --- Starting subTest AffinitySessionDrainTest.test_session_drain.08_test_client_csds_shows_chosen_server_draining ---
I0404 16:22:46.735103 140443674669056 xds_k8s_testcase.py:636] << Found EDS endpoints: HEALTHY: ['10.56.3.163:8080', '10.56.4.116:8080', '10.56.0.159:8080'], DRAINING: []
I0404 16:22:56.751447 140443674669056 xds_k8s_testcase.py:636] << Found EDS endpoints: HEALTHY: ['10.56.3.164:8080', '10.56.4.116:8080', '10.56.0.159:8080'], DRAINING: ['10.56.3.163:8080']
I0404 16:22:56.751761 140443674669056 xds_k8s_testcase.py:304] --- Finished subTest AffinitySessionDrainTest.test_session_drain.08_test_client_csds_shows_chosen_server_draining ---
I0404 16:22:56.751846 140443674669056 xds_k8s_testcase.py:299] --- Starting subTest AffinitySessionDrainTest.test_session_drain.09_pinned_traffic_stays_on_draining_server ---
I0404 16:22:56.752119 140443674669056 xds_k8s_testcase.py:506] Verifying RPCs go to servers ['psm-grpc-server-5d47686f44-4khxw']
I0404 16:22:56.752270 140443674669056 grpc.py:75] [psm-grpc-client-b94d5dbb4-4pc6r:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 100, 'timeoutSec': 1200, 'metadataKeys': ['set-cookie']}), timeout=1200, wait_for_ready=True)
I0404 16:23:00.833687 140443674669056 xds_k8s_testcase.py:669] [psm-grpc-client-b94d5dbb4-4pc6r] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-5d47686f44-4khxw: 100
rpcs_by_method:
UnaryCall:
psm-grpc-server-5d47686f44-4khxw: 100

I0404 16:23:00.834082 140443674669056 affinity_session_drain_test.py:174] Confirmed all RPCs with Cookie header are still sent to the chosen server while it's in the DRAINING state: psm-grpc-server-5d47686f44-4khxw
I0404 16:23:00.834186 140443674669056 xds_k8s_testcase.py:304] --- Finished subTest AffinitySessionDrainTest.test_session_drain.09_pinned_traffic_stays_on_draining_server ---
I0404 16:23:00.834240 140443674669056 xds_k8s_testcase.py:299] --- Starting subTest AffinitySessionDrainTest.test_session_drain.10_new_traffic_not_sent_to_draining_server ---
I0404 16:23:00.834294 140443674669056 affinity_session_drain_test.py:181] Configuring client to send no cookies
I0404 16:23:00.834428 140443674669056 grpc.py:75] [psm-grpc-client-b94d5dbb4-4pc6r:8079] >> RPC XdsUpdateClientConfigureService.Configure(request=ClientConfigureRequest({'types': ['UNARY_CALL']}), wait_for_ready=True, timeout=5)
I0404 16:23:00.838123 140443674669056 grpc.py:75] [psm-grpc-client-b94d5dbb4-4pc6r:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 120, 'timeoutSec': 1200, 'metadataKeys': ['set-cookie']}), timeout=1200, wait_for_ready=True)
I0404 16:23:05.748925 140443674669056 xds_k8s_testcase.py:669] [psm-grpc-client-b94d5dbb4-4pc6r] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-5d47686f44-m75pb: 42
psm-grpc-server-5d47686f44-bt44k: 36
psm-grpc-server-5d47686f44-69t5p: 42
rpcs_by_method:
UnaryCall:
psm-grpc-server-5d47686f44-m75pb: 42
psm-grpc-server-5d47686f44-bt44k: 36
psm-grpc-server-5d47686f44-69t5p: 42
metadatas_by_peer:
psm-grpc-server-5d47686f44-m75pb:
set-cookie:
- GSSA=MTAuNTYuNC4xMTY6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfMzEwNDExNjgzOTUxNTY0NzM5NQ==;
HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50
psm-grpc-server-5d47686f44-bt44k:
set-cookie:
- GSSA=MTAuNTYuMy4xNjQ6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfMzEwNDExNjgzOTUxNTY0NzM5NQ==;
HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50
psm-grpc-server-5d47686f44-69t5p:
set-cookie:
- GSSA=MTAuNTYuMC4xNTk6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfMzEwNDExNjgzOTUxNTY0NzM5NQ==;
HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50

I0404 16:23:05.749140 140443674669056 affinity_session_drain_test.py:197] Confirmed draining server psm-grpc-server-5d47686f44-4khxw received no new traffic, while {'psm-grpc-server-5d47686f44-m75pb', 'psm-grpc-server-5d47686f44-69t5p'} did
I0404 16:23:05.749247 140443674669056 xds_k8s_testcase.py:304] --- Finished subTest AffinitySessionDrainTest.test_session_drain.10_new_traffic_not_sent_to_draining_server ---
I0404 16:23:05.749336 140443674669056 xds_k8s_testcase.py:299] --- Starting subTest AffinitySessionDrainTest.test_session_drain.11_chosen_server_release_prestop ---
I0404 16:23:05.749387 140443674669056 affinity_session_drain_test.py:205] Releasing prestop hook on, psm-grpc-server-5d47686f44-4khxw
I0404 16:23:05.749766 140443674669056 grpc.py:75] [psm-grpc-server-5d47686f44-4khxw:8080] >> RPC HookService.SetReturnStatus(request=SetReturnStatusRequest({}), wait_for_ready=True, timeout=10)
I0404 16:23:05.755123 140443674669056 xds_k8s_testcase.py:304] --- Finished subTest AffinitySessionDrainTest.test_session_drain.11_chosen_server_release_prestop ---
I0404 16:23:05.755293 140443674669056 xds_k8s_testcase.py:299] --- Starting subTest AffinitySessionDrainTest.test_session_drain.12_confirm_chosen_server_stopped ---
I0404 16:23:05.755351 140443674669056 affinity_session_drain_test.py:209] Waiting on the chosen server to be deleted
I0404 16:23:07.869046 140443674669056 grpc.py:75] [psm-grpc-client-b94d5dbb4-4pc6r:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 30, 'timeoutSec': 1200, 'metadataKeys': ['set-cookie']}), timeout=1200, wait_for_ready=True)
I0404 16:23:09.163375 140443674669056 xds_k8s_testcase.py:669] [psm-grpc-client-b94d5dbb4-4pc6r] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-5d47686f44-m75pb: 7
psm-grpc-server-5d47686f44-bt44k: 16
psm-grpc-server-5d47686f44-69t5p: 7
rpcs_by_method:
UnaryCall:
psm-grpc-server-5d47686f44-m75pb: 7
psm-grpc-server-5d47686f44-bt44k: 16
psm-grpc-server-5d47686f44-69t5p: 7
metadatas_by_peer:
psm-grpc-server-5d47686f44-m75pb:
set-cookie:
- GSSA=MTAuNTYuNC4xMTY6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfMzEwNDExNjgzOTUxNTY0NzM5NQ==;
HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50
psm-grpc-server-5d47686f44-bt44k:
set-cookie:
- GSSA=MTAuNTYuMy4xNjQ6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfMzEwNDExNjgzOTUxNTY0NzM5NQ==;
HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50
psm-grpc-server-5d47686f44-69t5p:
set-cookie:
- GSSA=MTAuNTYuMC4xNTk6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfMzEwNDExNjgzOTUxNTY0NzM5NQ==;
HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50

I0404 16:23:09.163578 140443674669056 xds_k8s_testcase.py:304] --- Finished subTest AffinitySessionDrainTest.test_session_drain.12_confirm_chosen_server_stopped ---
I0404 16:23:09.163646 140443674669056 xds_k8s_testcase.py:299] --- Starting subTest AffinitySessionDrainTest.test_session_drain.13_get_new_cookie_and_new_server ---
I0404 16:23:09.163977 140443674669056 grpc.py:75] [psm-grpc-client-b94d5dbb4-4pc6r:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 1, 'timeoutSec': 1200, 'metadataKeys': ['set-cookie']}), timeout=1200, wait_for_ready=True)
I0404 16:23:09.281672 140443674669056 xds_k8s_testcase.py:669] [psm-grpc-client-b94d5dbb4-4pc6r] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-5d47686f44-m75pb: 1
rpcs_by_method:
UnaryCall:
psm-grpc-server-5d47686f44-m75pb: 1
metadatas_by_peer:
psm-grpc-server-5d47686f44-m75pb:
set-cookie:
- GSSA=MTAuNTYuNC4xMTY6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfMzEwNDExNjgzOTUxNTY0NzM5NQ==;
HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50

I0404 16:23:09.282082 140443674669056 affinity_session_drain_test.py:233] New chosen server: psm-grpc-server-5d47686f44-m75pb, cookie: GSSA=MTAuNTYuNC4xMTY6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfMzEwNDExNjgzOTUxNTY0NzM5NQ==; HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50
I0404 16:23:09.282179 140443674669056 xds_k8s_testcase.py:304] --- Finished subTest AffinitySessionDrainTest.test_session_drain.13_get_new_cookie_and_new_server ---
I0404 16:23:09.282237 140443674669056 xds_k8s_testcase.py:299] --- Starting subTest AffinitySessionDrainTest.test_session_drain.14_new_chosen_server_receives_rpcs_with_cookie ---
I0404 16:23:09.282285 140443674669056 affinity_session_drain_test.py:238] Configuring client to send cookie GSSA=MTAuNTYuMy4xNjM6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfMzEwNDExNjgzOTUxNTY0NzM5NQ==; HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50
I0404 16:23:09.282436 140443674669056 grpc.py:75] [psm-grpc-client-b94d5dbb4-4pc6r:8079] >> RPC XdsUpdateClientConfigureService.Configure(request=ClientConfigureRequest({'types': ['UNARY_CALL'], 'metadata': [{'type': 'UNARY_CALL', 'key': 'cookie', 'value': 'GSSA=MTAuNTYuNC4xMTY6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfMzEwNDExNjgzOTUxNTY0NzM5NQ==; HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50'}]}), wait_for_ready=True, timeout=5)
I0404 16:23:09.285581 140443674669056 xds_k8s_testcase.py:506] Verifying RPCs go to servers ['psm-grpc-server-5d47686f44-m75pb']
I0404 16:23:09.285802 140443674669056 grpc.py:75] [psm-grpc-client-b94d5dbb4-4pc6r:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 100, 'timeoutSec': 1200, 'metadataKeys': ['set-cookie']}), timeout=1200, wait_for_ready=True)
I0404 16:23:13.384979 140443674669056 xds_k8s_testcase.py:669] [psm-grpc-client-b94d5dbb4-4pc6r] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-5d47686f44-m75pb: 100
rpcs_by_method:
UnaryCall:
psm-grpc-server-5d47686f44-m75pb: 100

I0404 16:23:13.385368 140443674669056 affinity_session_drain_test.py:250] Confirmed all RPCs went to the new chosen server: psm-grpc-server-5d47686f44-m75pb
I0404 16:23:13.385472 140443674669056 xds_k8s_testcase.py:304] --- Finished subTest AffinitySessionDrainTest.test_session_drain.14_new_chosen_server_receives_rpcs_with_cookie ---
I0404 16:23:13.385563 140443674669056 xds_k8s_testcase.py:755] ----- TestMethod AffinitySessionDrainTest.test_session_drain teardown -----
I0404 16:23:13.478229 140443674669056 k8s_base_runner.py:873] Deleting deployment psm-grpc-client
I0404 16:23:23.640374 140443674669056 k8s_base_runner.py:888] Deployment psm-grpc-client deleted
I0404 16:23:23.640624 140443674669056 k8s_base_runner.py:924] Deleting namespace psm-csm-client-20240404-1620-7bkd7
I0404 16:23:53.757740 140443674669056 k8s_base_runner.py:941] Namespace psm-csm-client-20240404-1620-7bkd7 deleted
I0404 16:23:53.757958 140443674669056 k8s_base_runner.py:779] Deleting HTTPRoute route-psm-grpc-server
I0404 16:23:54.876541 140443674669056 k8s_base_runner.py:793] HTTPRoute route-psm-grpc-server deleted
I0404 16:23:54.876768 140443674669056 k8s_base_runner.py:891] Deleting service psm-csm-20240404-1620-7bkd7
I0404 16:23:54.954836 140443674669056 k8s_base_runner.py:904] Service psm-csm-20240404-1620-7bkd7 deleted
I0404 16:23:54.955016 140443674669056 k8s_base_runner.py:891] Deleting service psm-grpc-server
I0404 16:23:56.062912 140443674669056 k8s_base_runner.py:904] Service psm-grpc-server deleted
I0404 16:23:56.063103 140443674669056 k8s_base_runner.py:873] Deleting deployment psm-grpc-server
I0404 16:23:56.063191 140443674669056 k8s_xds_server_runner.py:337] [ns/psm-csm-server-20240404-1620-7bkd7] Releasing pre-stop hook on known server pods of deployment psm-grpc-server, deployment_id=psm-grpc-server-jib1mvk4
I0404 16:23:56.063317 140443674669056 grpc.py:75] [psm-grpc-server-5d47686f44-4khxw:8080] >> RPC HookService.SetReturnStatus(request=SetReturnStatusRequest({}), wait_for_ready=True, timeout=5)
I0404 16:24:01.064234 140443674669056 k8s_xds_server_runner.py:351] [ns/psm-csm-server-20240404-1620-7bkd7] Pre-stop hook release not executed on pod marked for deletion: psm-grpc-server-5d47686f44-4khxw (this is normal)
I0404 16:24:01.064705 140443674669056 grpc.py:75] [psm-grpc-server-5d47686f44-69t5p:8080] >> RPC HookService.SetReturnStatus(request=SetReturnStatusRequest({}), wait_for_ready=True, timeout=10)
I0404 16:24:01.071405 140443674669056 grpc.py:75] [psm-grpc-server-5d47686f44-m75pb:8080] >> RPC HookService.SetReturnStatus(request=SetReturnStatusRequest({}), wait_for_ready=True, timeout=10)
I0404 16:24:41.351183 140443674669056 k8s_base_runner.py:888] Deployment psm-grpc-server deleted
I0404 16:24:41.351433 140443674669056 k8s_base_runner.py:796] Deleting GCPSessionAffinityPolicy ssa-policy
I0404 16:24:41.449167 140443674669056 k8s_base_runner.py:816] GCPSessionAffinityPolicy ssa-policy deleted
I0404 16:24:41.449346 140443674669056 k8s_base_runner.py:819] Deleting GCPSessionAffinityFilter ssa-filter
I0404 16:24:41.482731 140443674669056 k8s_base_runner.py:856] Deleting GCPBackendPolicy backend-policy
I0404 16:24:51.575505 140443674669056 k8s_base_runner.py:870] GCPBackendPolicy backend-policy deleted
I0404 16:24:51.575708 140443674669056 k8s_base_runner.py:924] Deleting namespace psm-csm-server-20240404-1620-7bkd7
I0404 16:25:51.784280 140443674669056 k8s_base_runner.py:941] Namespace psm-csm-server-20240404-1620-7bkd7 deleted
I0404 16:25:51.784678 140443674669056 xds_k8s_testcase.py:779] ----- Test client/server logs -----
I0404 16:25:51.784936 140443674669056 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-client-aotw7wzl:
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-csm-client-20240404-1620-7bkd7%22%0Alabels.%22k8s-pod%2Fdeployment_id%22%3D%22psm-grpc-client-aotw7wzl%22;timeRange=2024-04-04T16:20:10.159814Z%2F2024-04-04T16:23:53.757925Z;cursorTimestamp=2024-04-04T16:20:14.473931Z?project=grpc-testing
I0404 16:25:51.785090 140443674669056 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-server-jib1mvk4:
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-csm-server-20240404-1620-7bkd7%22%0Alabels.%22k8s-pod%2Fdeployment_id%22%3D%22psm-grpc-server-jib1mvk4%22;timeRange=2024-04-04T16:20:02.041967Z%2F2024-04-04T16:25:51.784466Z;cursorTimestamp=2024-04-04T16:20:09.964850Z?project=grpc-testing
[ OK ] AffinitySessionDrainTest.test_session_drain
I0404 16:25:51.785354 140443674669056 base_testcase.py:67] ----- PSM Test Case PASSED: AffinitySessionDrainTest.test_session_drain -----

----------------------------------------------------------------------
Ran 1 test in 350.120s

OK
+ set +x
mkdir: created directory '/tmpfs/src/artifacts/grpc/core/master/linux/psm-csm-python/gamma.affinity_test'
+ python3 -m tests.gamma.affinity_test --flagfile=config/grpc-testing.cfg --flagfile=config/common-csm.cfg --kube_context=gke_grpc-testing_us-central1_psm-interop-csm --server_image=gcr.io/grpc-testing/xds-interop/cpp-server:64414d1b02f2038faec425523994a93ba4bcbe03 --client_image=gcr.io/grpc-testing/xds-interop/python-client:64414d1b02f2038faec425523994a93ba4bcbe03 --testing_version=dev-master --nocheck_local_certs --force_cleanup --collect_app_logs --log_dir=/tmpfs/src/artifacts/grpc/core/master/linux/psm-csm-python/gamma.affinity_test --xml_output_file=/tmpfs/src/artifacts/grpc/core/master/linux/psm-csm-python/gamma.affinity_test/sponge_log.xml
+ tee /tmpfs/src/artifacts/grpc/core/master/linux/psm-csm-python/gamma.affinity_test/sponge_log.log
Running tests under Python 3.10.12: /tmp/tmp.pWnnYGt0vw/psm-interop/venv/bin/python3
I0404 16:25:53.249461 140340686102528 xds_k8s_testcase.py:162] ----- Testing AffinityTest -----
I0404 16:25:53.249622 140340686102528 xds_k8s_testcase.py:163] Logs timezone: UTC
I0404 16:25:53.249870 140340686102528 xds_k8s_testcase.py:111] Detected language and version: TestConfig(client_lang='python', server_lang='cpp', version='dev-master')
I0404 16:25:53.262173 140340686102528 k8s.py:243] Using kubernetes context "gke_grpc-testing_us-central1_psm-interop-csm", active host: https://34.29.103.132
[ RUN ] AffinityTest.test_session_affinity_filter
I0404 16:25:53.267540 140340686102528 xds_k8s_testcase.py:736] Test run resource prefix: psm-csm, suffix: 20240404-1625-bzvph
I0404 16:25:53.600622 140340686102528 logs.py:31] Log root dir: /tmpfs/src/artifacts/grpc/core/master/linux/psm-csm-python/gamma.affinity_test
I0404 16:25:53.601309 140340686102528 xds_k8s_testcase.py:299] --- Starting subTest AffinityTest.test_session_affinity_filter.01_run_test_server ---
I0404 16:25:53.601422 140340686102528 gamma_server_runner.py:131] Deploying GAMMA xDS test server "psm-grpc-server" to k8s namespace psm-csm-server-20240404-1625-bzvph: test_port=8080 maintenance_port=8080 secure_mode=False replica_count=3
I0404 16:25:53.601633 140340686102528 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-csm-server-20240404-1625-bzvph%22;timeRange=2024-04-04T16:25:53.601486Z%2F2024-04-04T16:55:53.601486Z?project=grpc-testing
I0404 16:25:53.606626 140340686102528 k8s_base_runner.py:347] Rendered template kubernetes-manifests/namespace.yaml:
---
apiVersion: v1
kind: Namespace
metadata:
name: psm-csm-server-20240404-1625-bzvph
labels:
name: psm-csm-server-20240404-1625-bzvph
owner: xds-k8s-interop-test
...

I0404 16:25:53.721108 140340686102528 k8s_base_runner.py:367] Namespace psm-csm-server-20240404-1625-bzvph created
I0404 16:25:53.723645 140340686102528 k8s_base_runner.py:347] Rendered template kubernetes-manifests/gamma/service.yaml:
---
apiVersion: v1
kind: Service
metadata:
name: psm-grpc-server
namespace: psm-csm-server-20240404-1625-bzvph
labels:
owner: xds-k8s-interop-test
spec:
type: ClusterIP
selector:
app: psm-grpc-server
ports:
- port: 8080
protocol: TCP
targetPort: 8080
...

I0404 16:25:53.958067 140340686102528 k8s_base_runner.py:367] Service psm-grpc-server created
I0404 16:25:53.960050 140340686102528 k8s_base_runner.py:347] Rendered template kubernetes-manifests/gamma/frontend_service.yaml:
---
apiVersion: v1
kind: Service
metadata:
name: psm-csm-20240404-1625-bzvph
namespace: psm-csm-server-20240404-1625-bzvph
labels:
owner: xds-k8s-interop-test
spec:
ports:
- port: 8080
targetPort: 8080

I0404 16:25:54.040152 140340686102528 k8s_base_runner.py:367] Service psm-csm-20240404-1625-bzvph created
I0404 16:25:54.043173 140340686102528 k8s_base_runner.py:347] Rendered template kubernetes-manifests/gamma/route_http_ssafilter.yaml:
---
kind: HTTPRoute
apiVersion: gateway.networking.k8s.io/v1beta1
metadata:
name: route-psm-grpc-server
namespace: psm-csm-server-20240404-1625-bzvph
labels:
owner: xds-k8s-interop-test
spec:
parentRefs:
- name: psm-csm-20240404-1625-bzvph
namespace: psm-csm-server-20240404-1625-bzvph
group: ""
kind: Service
rules:
- matches:
- path:
type: Exact
value: /grpc.testing.TestService/UnaryCall
filters:
- type: ExtensionRef
extensionRef:
group: networking.gke.io
kind: GCPSessionAffinityFilter
name: ssa-filter
backendRefs:
- name: psm-grpc-server
port: 8080
...

I0404 16:25:54.092659 140340686102528 k8s_base_runner.py:367] HTTPRoute route-psm-grpc-server created
I0404 16:25:54.173532 140340686102528 k8s_base_runner.py:347] Rendered template kubernetes-manifests/server.deployment.yaml:
---
apiVersion: apps/v1
kind: Deployment
metadata:
name: psm-grpc-server
namespace: psm-csm-server-20240404-1625-bzvph
labels:
app: psm-grpc-server
deployment_id: psm-grpc-server-vynhv04o
owner: xds-k8s-interop-test
spec:
replicas: 3
selector:
matchLabels:
app: psm-grpc-server
deployment_id: psm-grpc-server-vynhv04o
template:
metadata:
labels:
app: psm-grpc-server
deployment_id: psm-grpc-server-vynhv04o
owner: xds-k8s-interop-test
spec:
containers:
- name: psm-grpc-server
image: gcr.io/grpc-testing/xds-interop/cpp-server:64414d1b02f2038faec425523994a93ba4bcbe03
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: gcr.io/grpc-testing/td-grpc-bootstrap:2bf1b5ed00f852ffea8d24759c6fa673acc9ef10
imagePullPolicy: Always
args:
- "--output=/tmp/bootstrap/td-grpc-bootstrap.json"
- "--vpc-network-name=default-vpc"
- "--node-metadata=app=psm-csm-server-20240404-1625-bzvph-psm-grpc-server"
- "--generate-mesh-id-experimental"
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

...

I0404 16:25:54.235337 140340686102528 k8s_base_runner.py:367] Deployment psm-grpc-server created
I0404 16:25:54.235525 140340686102528 k8s_base_runner.py:962] Waiting for deployment psm-grpc-server to initialize 3 pod(s)
I0404 16:25:55.315500 140340686102528 k8s_base_runner.py:972] Deployment psm-grpc-server initialized 3 pod(s): ['psm-grpc-server-77dfb548d7-lt6mj', 'psm-grpc-server-77dfb548d7-nd8lt', 'psm-grpc-server-77dfb548d7-q4l8m']
I0404 16:25:55.315833 140340686102528 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-77dfb548d7-lt6mj to start
I0404 16:25:57.403212 140340686102528 k8s_base_runner.py:985] Pod psm-grpc-server-77dfb548d7-lt6mj ready, IP: 10.56.0.160
I0404 16:25:57.403449 140340686102528 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-77dfb548d7-lt6mj to gamma.affinity_test/test_app_logs/psm-csm-server-20240404-1625-bzvph_psm-grpc-server-77dfb548d7-lt6mj.log
I0404 16:25:57.403859 140340590274112 k8s_log_collector.py:71] [ns/psm-csm-server-20240404-1625-bzvph] Starting log collection thread 140340590274112 for psm-grpc-server-77dfb548d7-lt6mj
I0404 16:25:57.404072 140340686102528 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-77dfb548d7-nd8lt to start
I0404 16:25:58.463656 140340686102528 k8s_base_runner.py:985] Pod psm-grpc-server-77dfb548d7-nd8lt ready, IP: 10.56.3.165
I0404 16:25:58.463886 140340686102528 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-77dfb548d7-nd8lt to gamma.affinity_test/test_app_logs/psm-csm-server-20240404-1625-bzvph_psm-grpc-server-77dfb548d7-nd8lt.log
I0404 16:25:58.464315 140340581881408 k8s_log_collector.py:71] [ns/psm-csm-server-20240404-1625-bzvph] Starting log collection thread 140340581881408 for psm-grpc-server-77dfb548d7-nd8lt
I0404 16:25:58.464517 140340686102528 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-77dfb548d7-q4l8m to start
I0404 16:25:58.521399 140340686102528 k8s_base_runner.py:985] Pod psm-grpc-server-77dfb548d7-q4l8m ready, IP: 10.56.4.117
I0404 16:25:58.521622 140340686102528 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-77dfb548d7-q4l8m to gamma.affinity_test/test_app_logs/psm-csm-server-20240404-1625-bzvph_psm-grpc-server-77dfb548d7-q4l8m.log
I0404 16:25:58.522034 140340573488704 k8s_log_collector.py:71] [ns/psm-csm-server-20240404-1625-bzvph] Starting log collection thread 140340573488704 for psm-grpc-server-77dfb548d7-q4l8m
I0404 16:25:58.522239 140340686102528 k8s_base_runner.py:944] Waiting for deployment psm-grpc-server to report 3 available replica(s)
I0404 16:26:00.602588 140340686102528 k8s_base_runner.py:953] Deployment psm-grpc-server has 3 replicas available
I0404 16:26:00.602866 140340686102528 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-csm-server-20240404-1625-bzvph
I0404 16:26:06.710731 140340686102528 k8s_base_runner.py:1068] Detected 'cloud.google.com/neg-status' annotation for Kubernetes Service psm-grpc-server, namespace psm-csm-server-20240404-1625-bzvph: neg_name=k8s1-58b57ac6-psm-csm-server-20240404-1-psm-grpc-se-80-4206499c, port=8080, zones=['us-central1-a', 'us-central1-c']
I0404 16:26:06.710939 140340686102528 xds_k8s_testcase.py:304] --- Finished subTest AffinityTest.test_session_affinity_filter.01_run_test_server ---
I0404 16:26:06.711025 140340686102528 xds_k8s_testcase.py:299] --- Starting subTest AffinityTest.test_session_affinity_filter.02_create_ssa_filter ---
I0404 16:26:06.712915 140340686102528 k8s_base_runner.py:347] Rendered template kubernetes-manifests/gamma/session_affinity_filter.yaml:
---
apiVersion: networking.gke.io/v1
kind: GCPSessionAffinityFilter
metadata:
name: ssa-filter
namespace: psm-csm-server-20240404-1625-bzvph
labels:
owner: xds-k8s-interop-test
spec:
statefulGeneratedCookie:
cookieTtlSeconds: 50
...

I0404 16:26:06.754024 140340686102528 k8s_base_runner.py:367] GCPSessionAffinityFilter ssa-filter created
I0404 16:26:06.754221 140340686102528 xds_k8s_testcase.py:304] --- Finished subTest AffinityTest.test_session_affinity_filter.02_create_ssa_filter ---
I0404 16:26:06.754289 140340686102528 xds_k8s_testcase.py:299] --- Starting subTest AffinityTest.test_session_affinity_filter.03_start_test_client ---
I0404 16:26:06.754379 140340686102528 k8s_xds_client_runner.py:119] Deploying xDS test client "psm-grpc-client" to k8s namespace psm-csm-client-20240404-1625-bzvph: server_target=xds:///psm-csm-20240404-1625-bzvph.psm-csm-server-20240404-1625-bzvph.svc.cluster.local:8080 rpc=UnaryCall qps=25 metadata='' secure_mode=False print_response=False
I0404 16:26:06.754624 140340686102528 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-csm-client-20240404-1625-bzvph%22;timeRange=2024-04-04T16:26:06.754495Z%2F2024-04-04T16:56:06.754495Z?project=grpc-testing
I0404 16:26:06.756539 140340686102528 k8s_base_runner.py:347] Rendered template kubernetes-manifests/namespace.yaml:
---
apiVersion: v1
kind: Namespace
metadata:
name: psm-csm-client-20240404-1625-bzvph
labels:
name: psm-csm-client-20240404-1625-bzvph
owner: xds-k8s-interop-test
...

I0404 16:26:06.772132 140340686102528 k8s_base_runner.py:367] Namespace psm-csm-client-20240404-1625-bzvph created
I0404 16:26:06.782190 140340686102528 k8s_base_runner.py:347] Rendered template kubernetes-manifests/client.deployment.yaml:
---
apiVersion: apps/v1
kind: Deployment
metadata:
name: psm-grpc-client
namespace: psm-csm-client-20240404-1625-bzvph
labels:
app: psm-grpc-client
deployment_id: psm-grpc-client-2io5q56w
owner: xds-k8s-interop-test
spec:
replicas: 1
selector:
matchLabels:
app: psm-grpc-client
deployment_id: psm-grpc-client-2io5q56w
template:
metadata:
labels:
app: psm-grpc-client
deployment_id: psm-grpc-client-2io5q56w
owner: xds-k8s-interop-test
spec:
containers:
- name: psm-grpc-client
image: gcr.io/grpc-testing/xds-interop/python-client:64414d1b02f2038faec425523994a93ba4bcbe03
imagePullPolicy: Always
startupProbe:
tcpSocket:
port: 8079
periodSeconds: 3
failureThreshold: 1000
args:
- "--server=xds:///psm-csm-20240404-1625-bzvph.psm-csm-server-20240404-1625-bzvph.svc.cluster.local:8080"
- "--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: gcr.io/grpc-testing/td-grpc-bootstrap:2bf1b5ed00f852ffea8d24759c6fa673acc9ef10
imagePullPolicy: Always
args:
- "--output=/tmp/bootstrap/td-grpc-bootstrap.json"
- "--vpc-network-name=default-vpc"
- "--generate-mesh-id-experimental"
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
...

I0404 16:26:06.842225 140340686102528 k8s_base_runner.py:367] Deployment psm-grpc-client created
I0404 16:26:06.842442 140340686102528 k8s_base_runner.py:962] Waiting for deployment psm-grpc-client to initialize 1 pod(s)
I0404 16:26:07.918390 140340686102528 k8s_base_runner.py:972] Deployment psm-grpc-client initialized 1 pod(s): ['psm-grpc-client-6fd97d8469-zsp9n']
I0404 16:26:07.918655 140340686102528 k8s_base_runner.py:982] Waiting for pod psm-grpc-client-6fd97d8469-zsp9n to start
I0404 16:26:09.997679 140340686102528 k8s_base_runner.py:985] Pod psm-grpc-client-6fd97d8469-zsp9n ready, IP: 10.56.2.123
I0404 16:26:09.997926 140340686102528 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-client-6fd97d8469-zsp9n to gamma.affinity_test/test_app_logs/psm-csm-client-20240404-1625-bzvph_psm-grpc-client-6fd97d8469-zsp9n.log
I0404 16:26:09.998339 140340564047424 k8s_log_collector.py:71] [ns/psm-csm-client-20240404-1625-bzvph] Starting log collection thread 140340564047424 for psm-grpc-client-6fd97d8469-zsp9n
I0404 16:26:09.998550 140340686102528 k8s_base_runner.py:944] Waiting for deployment psm-grpc-client to report 1 available replica(s)
I0404 16:26:12.071852 140340686102528 k8s_base_runner.py:953] Deployment psm-grpc-client has 1 replicas available
I0404 16:26:12.072264 140340686102528 client_app.py:292] [psm-grpc-client-6fd97d8469-zsp9n] ADS: Waiting for active calls to xDS control plane to trafficdirector.googleapis.com:443
I0404 16:26:12.097187 140340686102528 client_app.py:320] [psm-grpc-client-6fd97d8469-zsp9n] xDS control plane channel:
I0404 16:26:22.118730 140340686102528 client_app.py:320] [psm-grpc-client-6fd97d8469-zsp9n] xDS control plane channel:
I0404 16:26:32.130969 140340686102528 client_app.py:320] [psm-grpc-client-6fd97d8469-zsp9n] xDS control plane channel:
I0404 16:26:42.153244 140340686102528 client_app.py:320] [psm-grpc-client-6fd97d8469-zsp9n] xDS control plane channel:
I0404 16:26:52.173128 140340686102528 client_app.py:320] [psm-grpc-client-6fd97d8469-zsp9n] xDS control plane channel:
I0404 16:27:08.191226 140340686102528 client_app.py:320] [psm-grpc-client-6fd97d8469-zsp9n] xDS control plane channel:
I0404 16:27:33.226270 140340686102528 client_app.py:320] [psm-grpc-client-6fd97d8469-zsp9n] xDS control plane channel:
I0404 16:27:58.264497 140340686102528 client_app.py:320] [psm-grpc-client-6fd97d8469-zsp9n] xDS control plane channel:
I0404 16:28:00.273094 140340686102528 client_app.py:331] [psm-grpc-client-6fd97d8469-zsp9n] Detected active calls to xDS control plane trafficdirector.googleapis.com:443, channel:
I0404 16:28:00.273339 140340686102528 client_app.py:302] [psm-grpc-client-6fd97d8469-zsp9n] ADS: Detected active calls to xDS control plane trafficdirector.googleapis.com:443
I0404 16:28:00.273593 140340686102528 client_app.py:252] [psm-grpc-client-6fd97d8469-zsp9n] Waiting to report a READY channel to xds:///psm-csm-20240404-1625-bzvph.psm-csm-server-20240404-1625-bzvph.svc.cluster.local:8080
I0404 16:28:00.282347 140340686102528 client_app.py:379] [psm-grpc-client-6fd97d8469-zsp9n] Server channel:
I0404 16:28:00.282544 140340686102528 client_app.py:379] [psm-grpc-client-6fd97d8469-zsp9n] Server channel:
I0404 16:28:10.302311 140340686102528 client_app.py:379] [psm-grpc-client-6fd97d8469-zsp9n] Server channel:
I0404 16:28:10.302534 140340686102528 client_app.py:379] [psm-grpc-client-6fd97d8469-zsp9n] Server channel:
I0404 16:28:20.322359 140340686102528 client_app.py:379] [psm-grpc-client-6fd97d8469-zsp9n] Server channel:
I0404 16:28:20.322571 140340686102528 client_app.py:379] [psm-grpc-client-6fd97d8469-zsp9n] Server channel:
I0404 16:28:30.343225 140340686102528 client_app.py:379] [psm-grpc-client-6fd97d8469-zsp9n] Server channel:
I0404 16:28:30.343417 140340686102528 client_app.py:379] [psm-grpc-client-6fd97d8469-zsp9n] Server channel:
I0404 16:28:40.364143 140340686102528 client_app.py:379] [psm-grpc-client-6fd97d8469-zsp9n] Server channel:
I0404 16:28:40.368378 140340686102528 client_app.py:392] [psm-grpc-client-6fd97d8469-zsp9n] Found subchannel in state READY:
I0404 16:28:40.368642 140340686102528 client_app.py:263] [psm-grpc-client-6fd97d8469-zsp9n] Channel to xds:///psm-csm-20240404-1625-bzvph.psm-csm-server-20240404-1625-bzvph.svc.cluster.local:8080 transitioned to state READY:
I0404 16:28:40.368792 140340686102528 xds_k8s_testcase.py:304] --- Finished subTest AffinityTest.test_session_affinity_filter.03_start_test_client ---
I0404 16:28:40.368857 140340686102528 xds_k8s_testcase.py:299] --- Starting subTest AffinityTest.test_session_affinity_filter.04_send_first_RPC_and_retrieve_cookie ---
I0404 16:28:40.369333 140340686102528 grpc.py:75] [psm-grpc-client-6fd97d8469-zsp9n:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 1, 'timeoutSec': 1200, 'metadataKeys': ['*']}), wait_for_ready=True, timeout=1200)
I0404 16:28:40.489205 140340686102528 xds_k8s_testcase.py:669] [psm-grpc-client-6fd97d8469-zsp9n] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-77dfb548d7-nd8lt: 1
rpcs_by_method:
UnaryCall:
psm-grpc-server-77dfb548d7-nd8lt: 1
metadatas_by_peer:
psm-grpc-server-77dfb548d7-nd8lt:
hostname:
- psm-grpc-server-77dfb548d7-nd8lt
set-cookie:
- GSSA=MTAuNTYuMy4xNjU6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfNTA1NDk0OTY1MDMxNzE0MjU2Ng==;
HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50

I0404 16:28:40.489649 140340686102528 xds_k8s_testcase.py:304] --- Finished subTest AffinityTest.test_session_affinity_filter.04_send_first_RPC_and_retrieve_cookie ---
I0404 16:28:40.489759 140340686102528 xds_k8s_testcase.py:299] --- Starting subTest AffinityTest.test_session_affinity_filter.05_send_RPCs_with_cookie ---
I0404 16:28:40.489999 140340686102528 grpc.py:75] [psm-grpc-client-6fd97d8469-zsp9n:8079] >> RPC XdsUpdateClientConfigureService.Configure(request=ClientConfigureRequest({'types': ['UNARY_CALL'], 'metadata': [{'type': 'UNARY_CALL', 'key': 'cookie', 'value': 'GSSA=MTAuNTYuMy4xNjU6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfNTA1NDk0OTY1MDMxNzE0MjU2Ng==; HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50'}]}), wait_for_ready=True, timeout=5)
I0404 16:28:40.493456 140340686102528 xds_k8s_testcase.py:506] Verifying RPCs go to servers ['psm-grpc-server-77dfb548d7-nd8lt']
I0404 16:28:40.493715 140340686102528 grpc.py:75] [psm-grpc-client-6fd97d8469-zsp9n:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 10, 'timeoutSec': 1200, 'metadataKeys': ['*']}), wait_for_ready=True, timeout=1200)
I0404 16:28:40.972026 140340686102528 xds_k8s_testcase.py:669] [psm-grpc-client-6fd97d8469-zsp9n] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-77dfb548d7-nd8lt: 10
rpcs_by_method:
UnaryCall:
psm-grpc-server-77dfb548d7-nd8lt: 10
metadatas_by_peer:
psm-grpc-server-77dfb548d7-nd8lt:
hostname:
- psm-grpc-server-77dfb548d7-nd8lt

I0404 16:28:40.972406 140340686102528 xds_k8s_testcase.py:304] --- Finished subTest AffinityTest.test_session_affinity_filter.05_send_RPCs_with_cookie ---
I0404 16:28:40.972508 140340686102528 xds_k8s_testcase.py:755] ----- TestMethod AffinityTest.test_session_affinity_filter teardown -----
I0404 16:28:41.076226 140340686102528 k8s_base_runner.py:873] Deleting deployment psm-grpc-client
I0404 16:28:51.228235 140340686102528 k8s_base_runner.py:888] Deployment psm-grpc-client deleted
I0404 16:28:51.228486 140340686102528 k8s_base_runner.py:924] Deleting namespace psm-csm-client-20240404-1625-bzvph
I0404 16:29:21.335551 140340686102528 k8s_base_runner.py:941] Namespace psm-csm-client-20240404-1625-bzvph deleted
I0404 16:29:21.335797 140340686102528 k8s_base_runner.py:779] Deleting HTTPRoute route-psm-grpc-server
I0404 16:29:22.415777 140340686102528 k8s_base_runner.py:793] HTTPRoute route-psm-grpc-server deleted
I0404 16:29:22.415962 140340686102528 k8s_base_runner.py:891] Deleting service psm-csm-20240404-1625-bzvph
I0404 16:29:22.501236 140340686102528 k8s_base_runner.py:904] Service psm-csm-20240404-1625-bzvph deleted
I0404 16:29:22.501418 140340686102528 k8s_base_runner.py:891] Deleting service psm-grpc-server
I0404 16:29:23.614110 140340686102528 k8s_base_runner.py:904] Service psm-grpc-server deleted
I0404 16:29:23.614313 140340686102528 k8s_base_runner.py:873] Deleting deployment psm-grpc-server
I0404 16:29:33.798817 140340686102528 k8s_base_runner.py:888] Deployment psm-grpc-server deleted
I0404 16:29:33.799061 140340686102528 k8s_base_runner.py:796] Deleting GCPSessionAffinityPolicy ssa-policy
I0404 16:29:33.834005 140340686102528 k8s_base_runner.py:819] Deleting GCPSessionAffinityFilter ssa-filter
I0404 16:29:43.930869 140340686102528 k8s_base_runner.py:839] GCPSessionAffinityFilter ssa-filter deleted
I0404 16:29:43.931053 140340686102528 k8s_base_runner.py:856] Deleting GCPBackendPolicy backend-policy
I0404 16:29:43.959509 140340686102528 k8s_base_runner.py:924] Deleting namespace psm-csm-server-20240404-1625-bzvph
I0404 16:32:14.274630 140340686102528 k8s_base_runner.py:941] Namespace psm-csm-server-20240404-1625-bzvph deleted
I0404 16:32:14.275023 140340686102528 xds_k8s_testcase.py:779] ----- Test client/server logs -----
I0404 16:32:14.275240 140340686102528 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-client-2io5q56w:
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-csm-client-20240404-1625-bzvph%22%0Alabels.%22k8s-pod%2Fdeployment_id%22%3D%22psm-grpc-client-2io5q56w%22;timeRange=2024-04-04T16:26:06.754487Z%2F2024-04-04T16:29:21.335761Z;cursorTimestamp=2024-04-04T16:26:12.072062Z?project=grpc-testing
I0404 16:32:14.275370 140340686102528 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-server-vynhv04o:
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-csm-server-20240404-1625-bzvph%22%0Alabels.%22k8s-pod%2Fdeployment_id%22%3D%22psm-grpc-server-vynhv04o%22;timeRange=2024-04-04T16:25:53.601480Z%2F2024-04-04T16:32:14.274836Z;cursorTimestamp=2024-04-04T16:26:00.602804Z?project=grpc-testing
[ OK ] AffinityTest.test_session_affinity_filter
I0404 16:32:14.275679 140340686102528 base_testcase.py:67] ----- PSM Test Case PASSED: AffinityTest.test_session_affinity_filter -----

[ RUN ] AffinityTest.test_session_affinity_policy_with_route_target
I0404 16:32:14.275935 140340686102528 xds_k8s_testcase.py:736] Test run resource prefix: psm-csm, suffix: 20240404-1632-phyfa
I0404 16:32:14.276498 140340686102528 xds_k8s_testcase.py:299] --- Starting subTest AffinityTest.test_session_affinity_policy_with_route_target.01_run_test_server ---
I0404 16:32:14.276588 140340686102528 gamma_server_runner.py:131] Deploying GAMMA xDS test server "psm-grpc-server" to k8s namespace psm-csm-server-20240404-1632-phyfa: test_port=8080 maintenance_port=8080 secure_mode=False replica_count=3
I0404 16:32:14.276745 140340686102528 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-csm-server-20240404-1632-phyfa%22;timeRange=2024-04-04T16:32:14.276659Z%2F2024-04-04T17:02:14.276659Z?project=grpc-testing
I0404 16:32:14.277290 140340686102528 k8s_base_runner.py:347] Rendered template kubernetes-manifests/namespace.yaml:
---
apiVersion: v1
kind: Namespace
metadata:
name: psm-csm-server-20240404-1632-phyfa
labels:
name: psm-csm-server-20240404-1632-phyfa
owner: xds-k8s-interop-test
...

I0404 16:32:14.323228 140340686102528 k8s_base_runner.py:367] Namespace psm-csm-server-20240404-1632-phyfa created
I0404 16:32:14.324166 140340686102528 k8s_base_runner.py:347] Rendered template kubernetes-manifests/gamma/service.yaml:
---
apiVersion: v1
kind: Service
metadata:
name: psm-grpc-server
namespace: psm-csm-server-20240404-1632-phyfa
labels:
owner: xds-k8s-interop-test
spec:
type: ClusterIP
selector:
app: psm-grpc-server
ports:
- port: 8080
protocol: TCP
targetPort: 8080
...

I0404 16:32:14.453734 140340686102528 k8s_base_runner.py:367] Service psm-grpc-server created
I0404 16:32:14.454555 140340686102528 k8s_base_runner.py:347] Rendered template kubernetes-manifests/gamma/frontend_service.yaml:
---
apiVersion: v1
kind: Service
metadata:
name: psm-csm-20240404-1632-phyfa
namespace: psm-csm-server-20240404-1632-phyfa
labels:
owner: xds-k8s-interop-test
spec:
ports:
- port: 8080
targetPort: 8080

I0404 16:32:14.530625 140340686102528 k8s_base_runner.py:367] Service psm-csm-20240404-1632-phyfa created
I0404 16:32:14.533313 140340686102528 k8s_base_runner.py:347] Rendered template kubernetes-manifests/gamma/route_http.yaml:
---
kind: HTTPRoute
apiVersion: gateway.networking.k8s.io/v1beta1
metadata:
name: route-psm-grpc-server
namespace: psm-csm-server-20240404-1632-phyfa
labels:
owner: xds-k8s-interop-test
spec:
parentRefs:
- name: psm-csm-20240404-1632-phyfa
namespace: psm-csm-server-20240404-1632-phyfa
group: ""
kind: Service
rules:
- matches:
- path:
type: Exact
value: /grpc.testing.TestService/UnaryCall
backendRefs:
- name: psm-grpc-server
port: 8080
...

I0404 16:32:14.577613 140340686102528 k8s_base_runner.py:367] HTTPRoute route-psm-grpc-server created
I0404 16:32:14.580777 140340686102528 k8s_base_runner.py:347] Rendered template kubernetes-manifests/server.deployment.yaml:
---
apiVersion: apps/v1
kind: Deployment
metadata:
name: psm-grpc-server
namespace: psm-csm-server-20240404-1632-phyfa
labels:
app: psm-grpc-server
deployment_id: psm-grpc-server-ftlqwrxv
owner: xds-k8s-interop-test
spec:
replicas: 3
selector:
matchLabels:
app: psm-grpc-server
deployment_id: psm-grpc-server-ftlqwrxv
template:
metadata:
labels:
app: psm-grpc-server
deployment_id: psm-grpc-server-ftlqwrxv
owner: xds-k8s-interop-test
spec:
containers:
- name: psm-grpc-server
image: gcr.io/grpc-testing/xds-interop/cpp-server:64414d1b02f2038faec425523994a93ba4bcbe03
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: gcr.io/grpc-testing/td-grpc-bootstrap:2bf1b5ed00f852ffea8d24759c6fa673acc9ef10
imagePullPolicy: Always
args:
- "--output=/tmp/bootstrap/td-grpc-bootstrap.json"
- "--vpc-network-name=default-vpc"
- "--node-metadata=app=psm-csm-server-20240404-1632-phyfa-psm-grpc-server"
- "--generate-mesh-id-experimental"
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

...

I0404 16:32:14.639138 140340686102528 k8s_base_runner.py:367] Deployment psm-grpc-server created
I0404 16:32:14.639321 140340686102528 k8s_base_runner.py:962] Waiting for deployment psm-grpc-server to initialize 3 pod(s)
I0404 16:32:15.737414 140340686102528 k8s_base_runner.py:972] Deployment psm-grpc-server initialized 3 pod(s): ['psm-grpc-server-6b77ff6477-djl88', 'psm-grpc-server-6b77ff6477-pdjhj', 'psm-grpc-server-6b77ff6477-ppmsw']
I0404 16:32:15.737776 140340686102528 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-6b77ff6477-djl88 to start
I0404 16:32:17.826840 140340686102528 k8s_base_runner.py:985] Pod psm-grpc-server-6b77ff6477-djl88 ready, IP: 10.56.0.161
I0404 16:32:17.827053 140340686102528 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-6b77ff6477-djl88 to gamma.affinity_test/test_app_logs/psm-csm-server-20240404-1632-phyfa_psm-grpc-server-6b77ff6477-djl88.log
I0404 16:32:17.827398 140340590274112 k8s_log_collector.py:71] [ns/psm-csm-server-20240404-1632-phyfa] Starting log collection thread 140340590274112 for psm-grpc-server-6b77ff6477-djl88
I0404 16:32:17.827667 140340686102528 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-6b77ff6477-pdjhj to start
I0404 16:32:17.879156 140340686102528 k8s_base_runner.py:985] Pod psm-grpc-server-6b77ff6477-pdjhj ready, IP: 10.56.4.118
I0404 16:32:17.879366 140340686102528 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-6b77ff6477-pdjhj to gamma.affinity_test/test_app_logs/psm-csm-server-20240404-1632-phyfa_psm-grpc-server-6b77ff6477-pdjhj.log
I0404 16:32:17.879664 140340573488704 k8s_log_collector.py:71] [ns/psm-csm-server-20240404-1632-phyfa] Starting log collection thread 140340573488704 for psm-grpc-server-6b77ff6477-pdjhj
I0404 16:32:17.879938 140340686102528 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-6b77ff6477-ppmsw to start
I0404 16:32:17.929814 140340686102528 k8s_base_runner.py:985] Pod psm-grpc-server-6b77ff6477-ppmsw ready, IP: 10.56.3.166
I0404 16:32:17.930020 140340686102528 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-6b77ff6477-ppmsw to gamma.affinity_test/test_app_logs/psm-csm-server-20240404-1632-phyfa_psm-grpc-server-6b77ff6477-ppmsw.log
I0404 16:32:17.930331 140340581881408 k8s_log_collector.py:71] [ns/psm-csm-server-20240404-1632-phyfa] Starting log collection thread 140340581881408 for psm-grpc-server-6b77ff6477-ppmsw
I0404 16:32:17.930611 140340686102528 k8s_base_runner.py:944] Waiting for deployment psm-grpc-server to report 3 available replica(s)
I0404 16:32:20.010393 140340686102528 k8s_base_runner.py:953] Deployment psm-grpc-server has 3 replicas available
I0404 16:32:20.010691 140340686102528 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-csm-server-20240404-1632-phyfa
I0404 16:32:37.255808 140340686102528 k8s_base_runner.py:1068] Detected 'cloud.google.com/neg-status' annotation for Kubernetes Service psm-grpc-server, namespace psm-csm-server-20240404-1632-phyfa: neg_name=k8s1-58b57ac6-psm-csm-server-20240404-1-psm-grpc-se-80-57576f81, port=8080, zones=['us-central1-a', 'us-central1-c']
I0404 16:32:37.255998 140340686102528 xds_k8s_testcase.py:304] --- Finished subTest AffinityTest.test_session_affinity_policy_with_route_target.01_run_test_server ---
I0404 16:32:37.256064 140340686102528 xds_k8s_testcase.py:299] --- Starting subTest AffinityTest.test_session_affinity_policy_with_route_target.02_create_ssa_policy ---
I0404 16:32:37.258341 140340686102528 k8s_base_runner.py:347] Rendered template kubernetes-manifests/gamma/session_affinity_policy_route.yaml:
---
apiVersion: networking.gke.io/v1
kind: GCPSessionAffinityPolicy
metadata:
name: ssa-policy
namespace: psm-csm-server-20240404-1632-phyfa
labels:
owner: xds-k8s-interop-test
spec:
statefulGeneratedCookie:
cookieTtlSeconds: 50
targetRef:
name: route-psm-grpc-server
group: gateway.networking.k8s.io
kind: HTTPRoute
namespace: psm-csm-server-20240404-1632-phyfa
...

I0404 16:32:37.304276 140340686102528 k8s_base_runner.py:367] GCPSessionAffinityPolicy ssa-policy created
I0404 16:32:37.304473 140340686102528 xds_k8s_testcase.py:304] --- Finished subTest AffinityTest.test_session_affinity_policy_with_route_target.02_create_ssa_policy ---
I0404 16:32:37.304538 140340686102528 xds_k8s_testcase.py:299] --- Starting subTest AffinityTest.test_session_affinity_policy_with_route_target.03_start_test_client ---
I0404 16:32:37.304623 140340686102528 k8s_xds_client_runner.py:119] Deploying xDS test client "psm-grpc-client" to k8s namespace psm-csm-client-20240404-1632-phyfa: server_target=xds:///psm-csm-20240404-1632-phyfa.psm-csm-server-20240404-1632-phyfa.svc.cluster.local:8080 rpc=UnaryCall qps=25 metadata='' secure_mode=False print_response=False
I0404 16:32:37.304845 140340686102528 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-csm-client-20240404-1632-phyfa%22;timeRange=2024-04-04T16:32:37.304713Z%2F2024-04-04T17:02:37.304713Z?project=grpc-testing
I0404 16:32:37.305386 140340686102528 k8s_base_runner.py:347] Rendered template kubernetes-manifests/namespace.yaml:
---
apiVersion: v1
kind: Namespace
metadata:
name: psm-csm-client-20240404-1632-phyfa
labels:
name: psm-csm-client-20240404-1632-phyfa
owner: xds-k8s-interop-test
...

I0404 16:32:37.341200 140340686102528 k8s_base_runner.py:367] Namespace psm-csm-client-20240404-1632-phyfa created
I0404 16:32:37.345065 140340686102528 k8s_base_runner.py:347] Rendered template kubernetes-manifests/client.deployment.yaml:
---
apiVersion: apps/v1
kind: Deployment
metadata:
name: psm-grpc-client
namespace: psm-csm-client-20240404-1632-phyfa
labels:
app: psm-grpc-client
deployment_id: psm-grpc-client-ths8qg21
owner: xds-k8s-interop-test
spec:
replicas: 1
selector:
matchLabels:
app: psm-grpc-client
deployment_id: psm-grpc-client-ths8qg21
template:
metadata:
labels:
app: psm-grpc-client
deployment_id: psm-grpc-client-ths8qg21
owner: xds-k8s-interop-test
spec:
containers:
- name: psm-grpc-client
image: gcr.io/grpc-testing/xds-interop/python-client:64414d1b02f2038faec425523994a93ba4bcbe03
imagePullPolicy: Always
startupProbe:
tcpSocket:
port: 8079
periodSeconds: 3
failureThreshold: 1000
args:
- "--server=xds:///psm-csm-20240404-1632-phyfa.psm-csm-server-20240404-1632-phyfa.svc.cluster.local:8080"
- "--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: gcr.io/grpc-testing/td-grpc-bootstrap:2bf1b5ed00f852ffea8d24759c6fa673acc9ef10
imagePullPolicy: Always
args:
- "--output=/tmp/bootstrap/td-grpc-bootstrap.json"
- "--vpc-network-name=default-vpc"
- "--generate-mesh-id-experimental"
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
...

I0404 16:32:37.472048 140340686102528 k8s_base_runner.py:367] Deployment psm-grpc-client created
I0404 16:32:37.472239 140340686102528 k8s_base_runner.py:962] Waiting for deployment psm-grpc-client to initialize 1 pod(s)
I0404 16:32:38.580060 140340686102528 k8s_base_runner.py:972] Deployment psm-grpc-client initialized 1 pod(s): ['psm-grpc-client-7b64c8c755-ljllg']
I0404 16:32:38.580299 140340686102528 k8s_base_runner.py:982] Waiting for pod psm-grpc-client-7b64c8c755-ljllg to start
I0404 16:32:40.680356 140340686102528 k8s_base_runner.py:985] Pod psm-grpc-client-7b64c8c755-ljllg ready, IP: 10.56.2.124
I0404 16:32:40.680580 140340686102528 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-client-7b64c8c755-ljllg to gamma.affinity_test/test_app_logs/psm-csm-client-20240404-1632-phyfa_psm-grpc-client-7b64c8c755-ljllg.log
I0404 16:32:40.680934 140340564047424 k8s_log_collector.py:71] [ns/psm-csm-client-20240404-1632-phyfa] Starting log collection thread 140340564047424 for psm-grpc-client-7b64c8c755-ljllg
I0404 16:32:40.681164 140340686102528 k8s_base_runner.py:944] Waiting for deployment psm-grpc-client to report 1 available replica(s)
I0404 16:32:44.783445 140340686102528 k8s_base_runner.py:953] Deployment psm-grpc-client has 1 replicas available
I0404 16:32:44.783836 140340686102528 client_app.py:292] [psm-grpc-client-7b64c8c755-ljllg] ADS: Waiting for active calls to xDS control plane to trafficdirector.googleapis.com:443
I0404 16:32:44.803860 140340686102528 client_app.py:320] [psm-grpc-client-7b64c8c755-ljllg] xDS control plane channel:
I0404 16:32:54.824074 140340686102528 client_app.py:320] [psm-grpc-client-7b64c8c755-ljllg] xDS control plane channel:
I0404 16:33:04.846208 140340686102528 client_app.py:320] [psm-grpc-client-7b64c8c755-ljllg] xDS control plane channel:
I0404 16:33:14.866545 140340686102528 client_app.py:320] [psm-grpc-client-7b64c8c755-ljllg] xDS control plane channel:
I0404 16:33:24.886137 140340686102528 client_app.py:320] [psm-grpc-client-7b64c8c755-ljllg] xDS control plane channel:
I0404 16:33:40.911342 140340686102528 client_app.py:320] [psm-grpc-client-7b64c8c755-ljllg] xDS control plane channel:
I0404 16:34:05.946940 140340686102528 client_app.py:320] [psm-grpc-client-7b64c8c755-ljllg] xDS control plane channel:
I0404 16:34:30.982010 140340686102528 client_app.py:320] [psm-grpc-client-7b64c8c755-ljllg] xDS control plane channel:
I0404 16:34:56.017225 140340686102528 client_app.py:320] [psm-grpc-client-7b64c8c755-ljllg] xDS control plane channel:
I0404 16:35:21.052098 140340686102528 client_app.py:320] [psm-grpc-client-7b64c8c755-ljllg] xDS control plane channel:
I0404 16:35:46.078978 140340686102528 client_app.py:320] [psm-grpc-client-7b64c8c755-ljllg] xDS control plane channel:
I0404 16:35:48.087080 140340686102528 client_app.py:331] [psm-grpc-client-7b64c8c755-ljllg] Detected active calls to xDS control plane trafficdirector.googleapis.com:443, channel:
I0404 16:35:48.087347 140340686102528 client_app.py:302] [psm-grpc-client-7b64c8c755-ljllg] ADS: Detected active calls to xDS control plane trafficdirector.googleapis.com:443
I0404 16:35:48.087757 140340686102528 client_app.py:252] [psm-grpc-client-7b64c8c755-ljllg] Waiting to report a READY channel to xds:///psm-csm-20240404-1632-phyfa.psm-csm-server-20240404-1632-phyfa.svc.cluster.local:8080
I0404 16:35:48.096030 140340686102528 client_app.py:379] [psm-grpc-client-7b64c8c755-ljllg] Server channel:
I0404 16:35:48.099944 140340686102528 client_app.py:392] [psm-grpc-client-7b64c8c755-ljllg] Found subchannel in state READY:
I0404 16:35:48.100284 140340686102528 client_app.py:263] [psm-grpc-client-7b64c8c755-ljllg] Channel to xds:///psm-csm-20240404-1632-phyfa.psm-csm-server-20240404-1632-phyfa.svc.cluster.local:8080 transitioned to state READY:
I0404 16:35:48.100405 140340686102528 xds_k8s_testcase.py:304] --- Finished subTest AffinityTest.test_session_affinity_policy_with_route_target.03_start_test_client ---
I0404 16:35:48.100466 140340686102528 xds_k8s_testcase.py:299] --- Starting subTest AffinityTest.test_session_affinity_policy_with_route_target.04_send_first_RPC_and_retrieve_cookie ---
I0404 16:35:48.100881 140340686102528 grpc.py:75] [psm-grpc-client-7b64c8c755-ljllg:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 1, 'timeoutSec': 1200, 'metadataKeys': ['*']}), wait_for_ready=True, timeout=1200)
I0404 16:35:48.200765 140340686102528 xds_k8s_testcase.py:669] [psm-grpc-client-7b64c8c755-ljllg] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-6b77ff6477-ppmsw: 1
rpcs_by_method:
UnaryCall:
psm-grpc-server-6b77ff6477-ppmsw: 1
metadatas_by_peer:
psm-grpc-server-6b77ff6477-ppmsw:
hostname:
- psm-grpc-server-6b77ff6477-ppmsw

I0404 16:35:48.201347 140340686102528 retryers.py:213] Retrying framework.test_cases.session_affinity_util.assert_eventually_retrieve_cookie_and_server.._assert_retrieve_cookie_and_server in 10.0 seconds as it raised AssertionError: {} has length of 0, expected 1.
I0404 16:35:58.211759 140340686102528 grpc.py:75] [psm-grpc-client-7b64c8c755-ljllg:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 1, 'timeoutSec': 1200, 'metadataKeys': ['*']}), wait_for_ready=True, timeout=1200)
I0404 16:35:58.329999 140340686102528 xds_k8s_testcase.py:669] [psm-grpc-client-7b64c8c755-ljllg] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-6b77ff6477-ppmsw: 1
rpcs_by_method:
UnaryCall:
psm-grpc-server-6b77ff6477-ppmsw: 1
metadatas_by_peer:
psm-grpc-server-6b77ff6477-ppmsw:
hostname:
- psm-grpc-server-6b77ff6477-ppmsw

I0404 16:35:58.330341 140340686102528 retryers.py:213] Retrying framework.test_cases.session_affinity_util.assert_eventually_retrieve_cookie_and_server.._assert_retrieve_cookie_and_server in 10.0 seconds as it raised AssertionError: {} has length of 0, expected 1.
I0404 16:36:08.340703 140340686102528 grpc.py:75] [psm-grpc-client-7b64c8c755-ljllg:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 1, 'timeoutSec': 1200, 'metadataKeys': ['*']}), wait_for_ready=True, timeout=1200)
I0404 16:36:08.460573 140340686102528 xds_k8s_testcase.py:669] [psm-grpc-client-7b64c8c755-ljllg] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-6b77ff6477-djl88: 1
rpcs_by_method:
UnaryCall:
psm-grpc-server-6b77ff6477-djl88: 1
metadatas_by_peer:
psm-grpc-server-6b77ff6477-djl88:
hostname:
- psm-grpc-server-6b77ff6477-djl88

I0404 16:36:08.460903 140340686102528 retryers.py:213] Retrying framework.test_cases.session_affinity_util.assert_eventually_retrieve_cookie_and_server.._assert_retrieve_cookie_and_server in 10.0 seconds as it raised AssertionError: {} has length of 0, expected 1.
I0404 16:36:18.471231 140340686102528 grpc.py:75] [psm-grpc-client-7b64c8c755-ljllg:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 1, 'timeoutSec': 1200, 'metadataKeys': ['*']}), wait_for_ready=True, timeout=1200)
I0404 16:36:18.590179 140340686102528 xds_k8s_testcase.py:669] [psm-grpc-client-7b64c8c755-ljllg] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-6b77ff6477-ppmsw: 1
rpcs_by_method:
UnaryCall:
psm-grpc-server-6b77ff6477-ppmsw: 1
metadatas_by_peer:
psm-grpc-server-6b77ff6477-ppmsw:
hostname:
- psm-grpc-server-6b77ff6477-ppmsw

I0404 16:36:18.590566 140340686102528 retryers.py:213] Retrying framework.test_cases.session_affinity_util.assert_eventually_retrieve_cookie_and_server.._assert_retrieve_cookie_and_server in 10.0 seconds as it raised AssertionError: {} has length of 0, expected 1.
I0404 16:36:28.600958 140340686102528 grpc.py:75] [psm-grpc-client-7b64c8c755-ljllg:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 1, 'timeoutSec': 1200, 'metadataKeys': ['*']}), wait_for_ready=True, timeout=1200)
I0404 16:36:28.720355 140340686102528 xds_k8s_testcase.py:669] [psm-grpc-client-7b64c8c755-ljllg] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-6b77ff6477-djl88: 1
rpcs_by_method:
UnaryCall:
psm-grpc-server-6b77ff6477-djl88: 1
metadatas_by_peer:
psm-grpc-server-6b77ff6477-djl88:
hostname:
- psm-grpc-server-6b77ff6477-djl88
set-cookie:
- GSSA=MTAuNTYuMC4xNjE6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfMTMzMDg0MjMyMzIzNzY5MzYyOQ==;
HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50

I0404 16:36:28.720680 140340686102528 xds_k8s_testcase.py:304] --- Finished subTest AffinityTest.test_session_affinity_policy_with_route_target.04_send_first_RPC_and_retrieve_cookie ---
I0404 16:36:28.720775 140340686102528 xds_k8s_testcase.py:299] --- Starting subTest AffinityTest.test_session_affinity_policy_with_route_target.05_send_RPCs_with_cookie ---
I0404 16:36:28.720997 140340686102528 grpc.py:75] [psm-grpc-client-7b64c8c755-ljllg:8079] >> RPC XdsUpdateClientConfigureService.Configure(request=ClientConfigureRequest({'types': ['UNARY_CALL'], 'metadata': [{'type': 'UNARY_CALL', 'key': 'cookie', 'value': 'GSSA=MTAuNTYuMC4xNjE6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfMTMzMDg0MjMyMzIzNzY5MzYyOQ==; HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50'}]}), wait_for_ready=True, timeout=5)
I0404 16:36:28.724037 140340686102528 xds_k8s_testcase.py:506] Verifying RPCs go to servers ['psm-grpc-server-6b77ff6477-djl88']
I0404 16:36:28.724241 140340686102528 grpc.py:75] [psm-grpc-client-7b64c8c755-ljllg:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 10, 'timeoutSec': 1200, 'metadataKeys': ['*']}), wait_for_ready=True, timeout=1200)
I0404 16:36:29.204411 140340686102528 xds_k8s_testcase.py:669] [psm-grpc-client-7b64c8c755-ljllg] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-6b77ff6477-djl88: 10
rpcs_by_method:
UnaryCall:
psm-grpc-server-6b77ff6477-djl88: 10
metadatas_by_peer:
psm-grpc-server-6b77ff6477-djl88:
hostname:
- psm-grpc-server-6b77ff6477-djl88

I0404 16:36:29.204827 140340686102528 xds_k8s_testcase.py:304] --- Finished subTest AffinityTest.test_session_affinity_policy_with_route_target.05_send_RPCs_with_cookie ---
I0404 16:36:29.204952 140340686102528 xds_k8s_testcase.py:755] ----- TestMethod AffinityTest.test_session_affinity_policy_with_route_target teardown -----
I0404 16:36:29.335855 140340686102528 k8s_base_runner.py:873] Deleting deployment psm-grpc-client
I0404 16:36:39.458387 140340686102528 k8s_base_runner.py:888] Deployment psm-grpc-client deleted
I0404 16:36:39.458666 140340686102528 k8s_base_runner.py:924] Deleting namespace psm-csm-client-20240404-1632-phyfa
I0404 16:37:09.565974 140340686102528 k8s_base_runner.py:941] Namespace psm-csm-client-20240404-1632-phyfa deleted
I0404 16:37:09.566192 140340686102528 k8s_base_runner.py:779] Deleting HTTPRoute route-psm-grpc-server
I0404 16:37:10.643163 140340686102528 k8s_base_runner.py:793] HTTPRoute route-psm-grpc-server deleted
I0404 16:37:10.643347 140340686102528 k8s_base_runner.py:891] Deleting service psm-csm-20240404-1632-phyfa
I0404 16:37:11.734355 140340686102528 k8s_base_runner.py:904] Service psm-csm-20240404-1632-phyfa deleted
I0404 16:37:11.734590 140340686102528 k8s_base_runner.py:891] Deleting service psm-grpc-server
I0404 16:37:12.811572 140340686102528 k8s_base_runner.py:904] Service psm-grpc-server deleted
I0404 16:37:12.811770 140340686102528 k8s_base_runner.py:873] Deleting deployment psm-grpc-server
I0404 16:37:22.964110 140340686102528 k8s_base_runner.py:888] Deployment psm-grpc-server deleted
I0404 16:37:22.964429 140340686102528 k8s_base_runner.py:796] Deleting GCPSessionAffinityPolicy ssa-policy
I0404 16:37:23.054323 140340686102528 k8s_base_runner.py:816] GCPSessionAffinityPolicy ssa-policy deleted
I0404 16:37:23.054529 140340686102528 k8s_base_runner.py:819] Deleting GCPSessionAffinityFilter ssa-filter
I0404 16:37:23.084924 140340686102528 k8s_base_runner.py:856] Deleting GCPBackendPolicy backend-policy
I0404 16:37:23.117386 140340686102528 k8s_base_runner.py:924] Deleting namespace psm-csm-server-20240404-1632-phyfa
I0404 16:40:53.490731 140340686102528 k8s_base_runner.py:941] Namespace psm-csm-server-20240404-1632-phyfa deleted
I0404 16:40:53.491140 140340686102528 xds_k8s_testcase.py:779] ----- Test client/server logs -----
I0404 16:40:53.491365 140340686102528 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-client-ths8qg21:
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-csm-client-20240404-1632-phyfa%22%0Alabels.%22k8s-pod%2Fdeployment_id%22%3D%22psm-grpc-client-ths8qg21%22;timeRange=2024-04-04T16:32:37.304706Z%2F2024-04-04T16:37:09.566162Z;cursorTimestamp=2024-04-04T16:32:44.783643Z?project=grpc-testing
I0404 16:40:53.491500 140340686102528 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-server-ftlqwrxv:
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-csm-server-20240404-1632-phyfa%22%0Alabels.%22k8s-pod%2Fdeployment_id%22%3D%22psm-grpc-server-ftlqwrxv%22;timeRange=2024-04-04T16:32:14.276655Z%2F2024-04-04T16:40:53.490946Z;cursorTimestamp=2024-04-04T16:32:20.010624Z?project=grpc-testing
[ OK ] AffinityTest.test_session_affinity_policy_with_route_target
I0404 16:40:53.491808 140340686102528 base_testcase.py:67] ----- PSM Test Case PASSED: AffinityTest.test_session_affinity_policy_with_route_target -----

[ RUN ] AffinityTest.test_session_affinity_policy_with_service_target
I0404 16:40:53.492068 140340686102528 xds_k8s_testcase.py:736] Test run resource prefix: psm-csm, suffix: 20240404-1640-fq54f
I0404 16:40:53.492651 140340686102528 xds_k8s_testcase.py:299] --- Starting subTest AffinityTest.test_session_affinity_policy_with_service_target.01_run_test_server ---
I0404 16:40:53.492747 140340686102528 gamma_server_runner.py:131] Deploying GAMMA xDS test server "psm-grpc-server" to k8s namespace psm-csm-server-20240404-1640-fq54f: test_port=8080 maintenance_port=8080 secure_mode=False replica_count=3
I0404 16:40:53.492906 140340686102528 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-csm-server-20240404-1640-fq54f%22;timeRange=2024-04-04T16:40:53.492812Z%2F2024-04-04T17:10:53.492812Z?project=grpc-testing
I0404 16:40:53.493460 140340686102528 k8s_base_runner.py:347] Rendered template kubernetes-manifests/namespace.yaml:
---
apiVersion: v1
kind: Namespace
metadata:
name: psm-csm-server-20240404-1640-fq54f
labels:
name: psm-csm-server-20240404-1640-fq54f
owner: xds-k8s-interop-test
...

I0404 16:40:53.537945 140340686102528 k8s_base_runner.py:367] Namespace psm-csm-server-20240404-1640-fq54f created
I0404 16:40:53.538951 140340686102528 k8s_base_runner.py:347] Rendered template kubernetes-manifests/gamma/service.yaml:
---
apiVersion: v1
kind: Service
metadata:
name: psm-grpc-server
namespace: psm-csm-server-20240404-1640-fq54f
labels:
owner: xds-k8s-interop-test
spec:
type: ClusterIP
selector:
app: psm-grpc-server
ports:
- port: 8080
protocol: TCP
targetPort: 8080
...

I0404 16:40:53.655924 140340686102528 k8s_base_runner.py:367] Service psm-grpc-server created
I0404 16:40:53.656748 140340686102528 k8s_base_runner.py:347] Rendered template kubernetes-manifests/gamma/frontend_service.yaml:
---
apiVersion: v1
kind: Service
metadata:
name: psm-csm-20240404-1640-fq54f
namespace: psm-csm-server-20240404-1640-fq54f
labels:
owner: xds-k8s-interop-test
spec:
ports:
- port: 8080
targetPort: 8080

I0404 16:40:53.742831 140340686102528 k8s_base_runner.py:367] Service psm-csm-20240404-1640-fq54f created
I0404 16:40:53.744002 140340686102528 k8s_base_runner.py:347] Rendered template kubernetes-manifests/gamma/route_http.yaml:
---
kind: HTTPRoute
apiVersion: gateway.networking.k8s.io/v1beta1
metadata:
name: route-psm-grpc-server
namespace: psm-csm-server-20240404-1640-fq54f
labels:
owner: xds-k8s-interop-test
spec:
parentRefs:
- name: psm-csm-20240404-1640-fq54f
namespace: psm-csm-server-20240404-1640-fq54f
group: ""
kind: Service
rules:
- matches:
- path:
type: Exact
value: /grpc.testing.TestService/UnaryCall
backendRefs:
- name: psm-grpc-server
port: 8080
...

I0404 16:40:53.806263 140340686102528 k8s_base_runner.py:367] HTTPRoute route-psm-grpc-server created
I0404 16:40:53.809401 140340686102528 k8s_base_runner.py:347] Rendered template kubernetes-manifests/server.deployment.yaml:
---
apiVersion: apps/v1
kind: Deployment
metadata:
name: psm-grpc-server
namespace: psm-csm-server-20240404-1640-fq54f
labels:
app: psm-grpc-server
deployment_id: psm-grpc-server-wkoefrp2
owner: xds-k8s-interop-test
spec:
replicas: 3
selector:
matchLabels:
app: psm-grpc-server
deployment_id: psm-grpc-server-wkoefrp2
template:
metadata:
labels:
app: psm-grpc-server
deployment_id: psm-grpc-server-wkoefrp2
owner: xds-k8s-interop-test
spec:
containers:
- name: psm-grpc-server
image: gcr.io/grpc-testing/xds-interop/cpp-server:64414d1b02f2038faec425523994a93ba4bcbe03
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: gcr.io/grpc-testing/td-grpc-bootstrap:2bf1b5ed00f852ffea8d24759c6fa673acc9ef10
imagePullPolicy: Always
args:
- "--output=/tmp/bootstrap/td-grpc-bootstrap.json"
- "--vpc-network-name=default-vpc"
- "--node-metadata=app=psm-csm-server-20240404-1640-fq54f-psm-grpc-server"
- "--generate-mesh-id-experimental"
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

...

I0404 16:40:53.915722 140340686102528 k8s_base_runner.py:367] Deployment psm-grpc-server created
I0404 16:40:53.915920 140340686102528 k8s_base_runner.py:962] Waiting for deployment psm-grpc-server to initialize 3 pod(s)
I0404 16:40:55.017145 140340686102528 k8s_base_runner.py:972] Deployment psm-grpc-server initialized 3 pod(s): ['psm-grpc-server-55674c594b-8nlkm', 'psm-grpc-server-55674c594b-f4ffg', 'psm-grpc-server-55674c594b-z6tcc']
I0404 16:40:55.017513 140340686102528 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-55674c594b-8nlkm to start
I0404 16:40:58.121631 140340686102528 k8s_base_runner.py:985] Pod psm-grpc-server-55674c594b-8nlkm ready, IP: 10.56.4.119
I0404 16:40:58.121865 140340686102528 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-55674c594b-8nlkm to gamma.affinity_test/test_app_logs/psm-csm-server-20240404-1640-fq54f_psm-grpc-server-55674c594b-8nlkm.log
I0404 16:40:58.122206 140340573488704 k8s_log_collector.py:71] [ns/psm-csm-server-20240404-1640-fq54f] Starting log collection thread 140340573488704 for psm-grpc-server-55674c594b-8nlkm
I0404 16:40:58.122407 140340686102528 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-55674c594b-f4ffg to start
I0404 16:40:58.180387 140340686102528 k8s_base_runner.py:985] Pod psm-grpc-server-55674c594b-f4ffg ready, IP: 10.56.3.167
I0404 16:40:58.180620 140340686102528 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-55674c594b-f4ffg to gamma.affinity_test/test_app_logs/psm-csm-server-20240404-1640-fq54f_psm-grpc-server-55674c594b-f4ffg.log
I0404 16:40:58.180957 140340590274112 k8s_log_collector.py:71] [ns/psm-csm-server-20240404-1640-fq54f] Starting log collection thread 140340590274112 for psm-grpc-server-55674c594b-f4ffg
I0404 16:40:58.181138 140340686102528 k8s_base_runner.py:982] Waiting for pod psm-grpc-server-55674c594b-z6tcc to start
I0404 16:40:58.247999 140340686102528 k8s_base_runner.py:985] Pod psm-grpc-server-55674c594b-z6tcc ready, IP: 10.56.0.162
I0404 16:40:58.248220 140340686102528 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-server-55674c594b-z6tcc to gamma.affinity_test/test_app_logs/psm-csm-server-20240404-1640-fq54f_psm-grpc-server-55674c594b-z6tcc.log
I0404 16:40:58.248568 140340581881408 k8s_log_collector.py:71] [ns/psm-csm-server-20240404-1640-fq54f] Starting log collection thread 140340581881408 for psm-grpc-server-55674c594b-z6tcc
I0404 16:40:58.248770 140340686102528 k8s_base_runner.py:944] Waiting for deployment psm-grpc-server to report 3 available replica(s)
I0404 16:40:59.310000 140340686102528 k8s_base_runner.py:953] Deployment psm-grpc-server has 3 replicas available
I0404 16:40:59.310278 140340686102528 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-csm-server-20240404-1640-fq54f
I0404 16:41:07.465365 140340686102528 k8s_base_runner.py:1068] Detected 'cloud.google.com/neg-status' annotation for Kubernetes Service psm-grpc-server, namespace psm-csm-server-20240404-1640-fq54f: neg_name=k8s1-58b57ac6-psm-csm-server-20240404-1-psm-grpc-se-80-84bc8979, port=8080, zones=['us-central1-a', 'us-central1-c']
I0404 16:41:07.465574 140340686102528 xds_k8s_testcase.py:304] --- Finished subTest AffinityTest.test_session_affinity_policy_with_service_target.01_run_test_server ---
I0404 16:41:07.465641 140340686102528 xds_k8s_testcase.py:299] --- Starting subTest AffinityTest.test_session_affinity_policy_with_service_target.02_create_ssa_policy ---
I0404 16:41:07.468210 140340686102528 k8s_base_runner.py:347] Rendered template kubernetes-manifests/gamma/session_affinity_policy_service.yaml:
---
apiVersion: networking.gke.io/v1
kind: GCPSessionAffinityPolicy
metadata:
name: ssa-policy
namespace: psm-csm-server-20240404-1640-fq54f
labels:
owner: xds-k8s-interop-test
spec:
statefulGeneratedCookie:
cookieTtlSeconds: 50
targetRef:
name: psm-grpc-server
kind: Service
namespace: psm-csm-server-20240404-1640-fq54f
group: ""
...

I0404 16:41:07.505623 140340686102528 k8s_base_runner.py:367] GCPSessionAffinityPolicy ssa-policy created
I0404 16:41:07.505825 140340686102528 xds_k8s_testcase.py:304] --- Finished subTest AffinityTest.test_session_affinity_policy_with_service_target.02_create_ssa_policy ---
I0404 16:41:07.505897 140340686102528 xds_k8s_testcase.py:299] --- Starting subTest AffinityTest.test_session_affinity_policy_with_service_target.03_start_test_client ---
I0404 16:41:07.505985 140340686102528 k8s_xds_client_runner.py:119] Deploying xDS test client "psm-grpc-client" to k8s namespace psm-csm-client-20240404-1640-fq54f: server_target=xds:///psm-csm-20240404-1640-fq54f.psm-csm-server-20240404-1640-fq54f.svc.cluster.local:8080 rpc=UnaryCall qps=25 metadata='' secure_mode=False print_response=False
I0404 16:41:07.506174 140340686102528 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-csm-client-20240404-1640-fq54f%22;timeRange=2024-04-04T16:41:07.506065Z%2F2024-04-04T17:11:07.506065Z?project=grpc-testing
I0404 16:41:07.506783 140340686102528 k8s_base_runner.py:347] Rendered template kubernetes-manifests/namespace.yaml:
---
apiVersion: v1
kind: Namespace
metadata:
name: psm-csm-client-20240404-1640-fq54f
labels:
name: psm-csm-client-20240404-1640-fq54f
owner: xds-k8s-interop-test
...

I0404 16:41:07.533150 140340686102528 k8s_base_runner.py:367] Namespace psm-csm-client-20240404-1640-fq54f created
I0404 16:41:07.536706 140340686102528 k8s_base_runner.py:347] Rendered template kubernetes-manifests/client.deployment.yaml:
---
apiVersion: apps/v1
kind: Deployment
metadata:
name: psm-grpc-client
namespace: psm-csm-client-20240404-1640-fq54f
labels:
app: psm-grpc-client
deployment_id: psm-grpc-client-udp747jk
owner: xds-k8s-interop-test
spec:
replicas: 1
selector:
matchLabels:
app: psm-grpc-client
deployment_id: psm-grpc-client-udp747jk
template:
metadata:
labels:
app: psm-grpc-client
deployment_id: psm-grpc-client-udp747jk
owner: xds-k8s-interop-test
spec:
containers:
- name: psm-grpc-client
image: gcr.io/grpc-testing/xds-interop/python-client:64414d1b02f2038faec425523994a93ba4bcbe03
imagePullPolicy: Always
startupProbe:
tcpSocket:
port: 8079
periodSeconds: 3
failureThreshold: 1000
args:
- "--server=xds:///psm-csm-20240404-1640-fq54f.psm-csm-server-20240404-1640-fq54f.svc.cluster.local:8080"
- "--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: gcr.io/grpc-testing/td-grpc-bootstrap:2bf1b5ed00f852ffea8d24759c6fa673acc9ef10
imagePullPolicy: Always
args:
- "--output=/tmp/bootstrap/td-grpc-bootstrap.json"
- "--vpc-network-name=default-vpc"
- "--generate-mesh-id-experimental"
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
...

I0404 16:41:07.601658 140340686102528 k8s_base_runner.py:367] Deployment psm-grpc-client created
I0404 16:41:07.601852 140340686102528 k8s_base_runner.py:962] Waiting for deployment psm-grpc-client to initialize 1 pod(s)
I0404 16:41:08.700061 140340686102528 k8s_base_runner.py:972] Deployment psm-grpc-client initialized 1 pod(s): ['psm-grpc-client-6869fd9797-drcwc']
I0404 16:41:08.700292 140340686102528 k8s_base_runner.py:982] Waiting for pod psm-grpc-client-6869fd9797-drcwc to start
I0404 16:41:10.790851 140340686102528 k8s_base_runner.py:985] Pod psm-grpc-client-6869fd9797-drcwc ready, IP: 10.56.2.125
I0404 16:41:10.791073 140340686102528 k8s_base_runner.py:1030] Enabling log collection from pod psm-grpc-client-6869fd9797-drcwc to gamma.affinity_test/test_app_logs/psm-csm-client-20240404-1640-fq54f_psm-grpc-client-6869fd9797-drcwc.log
I0404 16:41:10.791431 140340564047424 k8s_log_collector.py:71] [ns/psm-csm-client-20240404-1640-fq54f] Starting log collection thread 140340564047424 for psm-grpc-client-6869fd9797-drcwc
I0404 16:41:10.791718 140340686102528 k8s_base_runner.py:944] Waiting for deployment psm-grpc-client to report 1 available replica(s)
I0404 16:41:11.847892 140340686102528 k8s_base_runner.py:953] Deployment psm-grpc-client has 1 replicas available
I0404 16:41:11.848318 140340686102528 client_app.py:292] [psm-grpc-client-6869fd9797-drcwc] ADS: Waiting for active calls to xDS control plane to trafficdirector.googleapis.com:443
I0404 16:41:11.868224 140340686102528 client_app.py:320] [psm-grpc-client-6869fd9797-drcwc] xDS control plane channel:
I0404 16:41:21.887830 140340686102528 client_app.py:320] [psm-grpc-client-6869fd9797-drcwc] xDS control plane channel:
I0404 16:41:31.907980 140340686102528 client_app.py:320] [psm-grpc-client-6869fd9797-drcwc] xDS control plane channel:
I0404 16:41:41.927839 140340686102528 client_app.py:320] [psm-grpc-client-6869fd9797-drcwc] xDS control plane channel:
I0404 16:41:51.947225 140340686102528 client_app.py:320] [psm-grpc-client-6869fd9797-drcwc] xDS control plane channel:
I0404 16:42:07.974909 140340686102528 client_app.py:320] [psm-grpc-client-6869fd9797-drcwc] xDS control plane channel:
I0404 16:42:32.995376 140340686102528 client_app.py:320] [psm-grpc-client-6869fd9797-drcwc] xDS control plane channel:
I0404 16:42:58.029897 140340686102528 client_app.py:320] [psm-grpc-client-6869fd9797-drcwc] xDS control plane channel:
I0404 16:43:23.066176 140340686102528 client_app.py:320] [psm-grpc-client-6869fd9797-drcwc] xDS control plane channel:
I0404 16:43:25.075274 140340686102528 client_app.py:331] [psm-grpc-client-6869fd9797-drcwc] Detected active calls to xDS control plane trafficdirector.googleapis.com:443, channel:
I0404 16:43:25.075528 140340686102528 client_app.py:302] [psm-grpc-client-6869fd9797-drcwc] ADS: Detected active calls to xDS control plane trafficdirector.googleapis.com:443
I0404 16:43:25.075795 140340686102528 client_app.py:252] [psm-grpc-client-6869fd9797-drcwc] Waiting to report a READY channel to xds:///psm-csm-20240404-1640-fq54f.psm-csm-server-20240404-1640-fq54f.svc.cluster.local:8080
I0404 16:43:25.085153 140340686102528 client_app.py:379] [psm-grpc-client-6869fd9797-drcwc] Server channel:
I0404 16:43:25.089984 140340686102528 client_app.py:392] [psm-grpc-client-6869fd9797-drcwc] Found subchannel in state READY:
I0404 16:43:25.090334 140340686102528 client_app.py:263] [psm-grpc-client-6869fd9797-drcwc] Channel to xds:///psm-csm-20240404-1640-fq54f.psm-csm-server-20240404-1640-fq54f.svc.cluster.local:8080 transitioned to state READY:
I0404 16:43:25.090508 140340686102528 xds_k8s_testcase.py:304] --- Finished subTest AffinityTest.test_session_affinity_policy_with_service_target.03_start_test_client ---
I0404 16:43:25.090614 140340686102528 xds_k8s_testcase.py:299] --- Starting subTest AffinityTest.test_session_affinity_policy_with_service_target.04_send_first_RPC_and_retrieve_cookie ---
I0404 16:43:25.091052 140340686102528 grpc.py:75] [psm-grpc-client-6869fd9797-drcwc:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 1, 'timeoutSec': 1200, 'metadataKeys': ['*']}), wait_for_ready=True, timeout=1200)
I0404 16:43:25.186545 140340686102528 xds_k8s_testcase.py:669] [psm-grpc-client-6869fd9797-drcwc] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-55674c594b-f4ffg: 1
rpcs_by_method:
UnaryCall:
psm-grpc-server-55674c594b-f4ffg: 1
metadatas_by_peer:
psm-grpc-server-55674c594b-f4ffg:
hostname:
- psm-grpc-server-55674c594b-f4ffg

I0404 16:43:25.187113 140340686102528 retryers.py:213] Retrying framework.test_cases.session_affinity_util.assert_eventually_retrieve_cookie_and_server.._assert_retrieve_cookie_and_server in 10.0 seconds as it raised AssertionError: {} has length of 0, expected 1.
I0404 16:43:35.197511 140340686102528 grpc.py:75] [psm-grpc-client-6869fd9797-drcwc:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 1, 'timeoutSec': 1200, 'metadataKeys': ['*']}), wait_for_ready=True, timeout=1200)
I0404 16:43:35.319106 140340686102528 xds_k8s_testcase.py:669] [psm-grpc-client-6869fd9797-drcwc] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-55674c594b-f4ffg: 1
rpcs_by_method:
UnaryCall:
psm-grpc-server-55674c594b-f4ffg: 1
metadatas_by_peer:
psm-grpc-server-55674c594b-f4ffg:
hostname:
- psm-grpc-server-55674c594b-f4ffg

I0404 16:43:35.319437 140340686102528 retryers.py:213] Retrying framework.test_cases.session_affinity_util.assert_eventually_retrieve_cookie_and_server.._assert_retrieve_cookie_and_server in 10.0 seconds as it raised AssertionError: {} has length of 0, expected 1.
I0404 16:43:45.329836 140340686102528 grpc.py:75] [psm-grpc-client-6869fd9797-drcwc:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 1, 'timeoutSec': 1200, 'metadataKeys': ['*']}), wait_for_ready=True, timeout=1200)
I0404 16:43:45.418895 140340686102528 xds_k8s_testcase.py:669] [psm-grpc-client-6869fd9797-drcwc] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-55674c594b-z6tcc: 1
rpcs_by_method:
UnaryCall:
psm-grpc-server-55674c594b-z6tcc: 1
metadatas_by_peer:
psm-grpc-server-55674c594b-z6tcc:
hostname:
- psm-grpc-server-55674c594b-z6tcc

I0404 16:43:45.419243 140340686102528 retryers.py:213] Retrying framework.test_cases.session_affinity_util.assert_eventually_retrieve_cookie_and_server.._assert_retrieve_cookie_and_server in 10.0 seconds as it raised AssertionError: {} has length of 0, expected 1.
I0404 16:43:55.424468 140340686102528 grpc.py:75] [psm-grpc-client-6869fd9797-drcwc:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 1, 'timeoutSec': 1200, 'metadataKeys': ['*']}), wait_for_ready=True, timeout=1200)
I0404 16:43:55.549322 140340686102528 xds_k8s_testcase.py:669] [psm-grpc-client-6869fd9797-drcwc] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-55674c594b-8nlkm: 1
rpcs_by_method:
UnaryCall:
psm-grpc-server-55674c594b-8nlkm: 1
metadatas_by_peer:
psm-grpc-server-55674c594b-8nlkm:
hostname:
- psm-grpc-server-55674c594b-8nlkm

I0404 16:43:55.549679 140340686102528 retryers.py:213] Retrying framework.test_cases.session_affinity_util.assert_eventually_retrieve_cookie_and_server.._assert_retrieve_cookie_and_server in 10.0 seconds as it raised AssertionError: {} has length of 0, expected 1.
I0404 16:44:05.560039 140340686102528 grpc.py:75] [psm-grpc-client-6869fd9797-drcwc:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 1, 'timeoutSec': 1200, 'metadataKeys': ['*']}), wait_for_ready=True, timeout=1200)
I0404 16:44:05.679965 140340686102528 xds_k8s_testcase.py:669] [psm-grpc-client-6869fd9797-drcwc] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-55674c594b-z6tcc: 1
rpcs_by_method:
UnaryCall:
psm-grpc-server-55674c594b-z6tcc: 1
metadatas_by_peer:
psm-grpc-server-55674c594b-z6tcc:
hostname:
- psm-grpc-server-55674c594b-z6tcc

I0404 16:44:05.680312 140340686102528 retryers.py:213] Retrying framework.test_cases.session_affinity_util.assert_eventually_retrieve_cookie_and_server.._assert_retrieve_cookie_and_server in 10.0 seconds as it raised AssertionError: {} has length of 0, expected 1.
I0404 16:44:15.690711 140340686102528 grpc.py:75] [psm-grpc-client-6869fd9797-drcwc:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 1, 'timeoutSec': 1200, 'metadataKeys': ['*']}), wait_for_ready=True, timeout=1200)
I0404 16:44:15.816297 140340686102528 xds_k8s_testcase.py:669] [psm-grpc-client-6869fd9797-drcwc] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-55674c594b-f4ffg: 1
rpcs_by_method:
UnaryCall:
psm-grpc-server-55674c594b-f4ffg: 1
metadatas_by_peer:
psm-grpc-server-55674c594b-f4ffg:
hostname:
- psm-grpc-server-55674c594b-f4ffg
set-cookie:
- GSSA=MTAuNTYuMy4xNjc6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfNjkwNDc5NjYzODg0NDUxMTk1OA==;
HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50

I0404 16:44:15.816645 140340686102528 xds_k8s_testcase.py:304] --- Finished subTest AffinityTest.test_session_affinity_policy_with_service_target.04_send_first_RPC_and_retrieve_cookie ---
I0404 16:44:15.816738 140340686102528 xds_k8s_testcase.py:299] --- Starting subTest AffinityTest.test_session_affinity_policy_with_service_target.05_send_RPCs_with_cookie ---
I0404 16:44:15.816972 140340686102528 grpc.py:75] [psm-grpc-client-6869fd9797-drcwc:8079] >> RPC XdsUpdateClientConfigureService.Configure(request=ClientConfigureRequest({'types': ['UNARY_CALL'], 'metadata': [{'type': 'UNARY_CALL', 'key': 'cookie', 'value': 'GSSA=MTAuNTYuMy4xNjc6ODA4MDtjbG91ZC1pbnRlcm5hbC1pc3RpbzpjbG91ZF9tcF84MzAyOTMyNjMzODRfNjkwNDc5NjYzODg0NDUxMTk1OA==; HttpOnly; Path=/grpc.testing.TestService/UnaryCall; Max-Age=50'}]}), wait_for_ready=True, timeout=5)
I0404 16:44:15.820431 140340686102528 xds_k8s_testcase.py:506] Verifying RPCs go to servers ['psm-grpc-server-55674c594b-f4ffg']
I0404 16:44:15.820731 140340686102528 grpc.py:75] [psm-grpc-client-6869fd9797-drcwc:8079] >> RPC LoadBalancerStatsService.GetClientStats(request=LoadBalancerStatsRequest({'numRpcs': 10, 'timeoutSec': 1200, 'metadataKeys': ['*']}), wait_for_ready=True, timeout=1200)
I0404 16:44:16.299634 140340686102528 xds_k8s_testcase.py:669] [psm-grpc-client-6869fd9797-drcwc] << Received LoadBalancerStatsResponse:
num_failures: 0
rpcs_by_peer:
psm-grpc-server-55674c594b-f4ffg: 10
rpcs_by_method:
UnaryCall:
psm-grpc-server-55674c594b-f4ffg: 10
metadatas_by_peer:
psm-grpc-server-55674c594b-f4ffg:
hostname:
- psm-grpc-server-55674c594b-f4ffg

I0404 16:44:16.300033 140340686102528 xds_k8s_testcase.py:304] --- Finished subTest AffinityTest.test_session_affinity_policy_with_service_target.05_send_RPCs_with_cookie ---
I0404 16:44:16.300149 140340686102528 xds_k8s_testcase.py:755] ----- TestMethod AffinityTest.test_session_affinity_policy_with_service_target teardown -----
I0404 16:44:16.429951 140340686102528 k8s_base_runner.py:873] Deleting deployment psm-grpc-client
I0404 16:44:26.604619 140340686102528 k8s_base_runner.py:888] Deployment psm-grpc-client deleted
I0404 16:44:26.604900 140340686102528 k8s_base_runner.py:924] Deleting namespace psm-csm-client-20240404-1640-fq54f
I0404 16:44:56.710278 140340686102528 k8s_base_runner.py:941] Namespace psm-csm-client-20240404-1640-fq54f deleted
I0404 16:44:56.710533 140340686102528 k8s_base_runner.py:779] Deleting HTTPRoute route-psm-grpc-server
I0404 16:44:57.798835 140340686102528 k8s_base_runner.py:793] HTTPRoute route-psm-grpc-server deleted
I0404 16:44:57.799012 140340686102528 k8s_base_runner.py:891] Deleting service psm-csm-20240404-1640-fq54f
I0404 16:44:58.879278 140340686102528 k8s_base_runner.py:904] Service psm-csm-20240404-1640-fq54f deleted
I0404 16:44:58.879462 140340686102528 k8s_base_runner.py:891] Deleting service psm-grpc-server
I0404 16:44:59.963088 140340686102528 k8s_base_runner.py:904] Service psm-grpc-server deleted
I0404 16:44:59.963276 140340686102528 k8s_base_runner.py:873] Deleting deployment psm-grpc-server
I0404 16:45:10.106507 140340686102528 k8s_base_runner.py:888] Deployment psm-grpc-server deleted
I0404 16:45:10.106784 140340686102528 k8s_base_runner.py:796] Deleting GCPSessionAffinityPolicy ssa-policy
I0404 16:45:20.203361 140340686102528 k8s_base_runner.py:816] GCPSessionAffinityPolicy ssa-policy deleted
I0404 16:45:20.203535 140340686102528 k8s_base_runner.py:819] Deleting GCPSessionAffinityFilter ssa-filter
I0404 16:45:20.232216 140340686102528 k8s_base_runner.py:856] Deleting GCPBackendPolicy backend-policy
I0404 16:45:20.266558 140340686102528 k8s_base_runner.py:924] Deleting namespace psm-csm-server-20240404-1640-fq54f
I0404 16:46:50.526982 140340686102528 k8s_base_runner.py:941] Namespace psm-csm-server-20240404-1640-fq54f deleted
I0404 16:46:50.527365 140340686102528 xds_k8s_testcase.py:779] ----- Test client/server logs -----
I0404 16:46:50.527581 140340686102528 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-client-udp747jk:
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-csm-client-20240404-1640-fq54f%22%0Alabels.%22k8s-pod%2Fdeployment_id%22%3D%22psm-grpc-client-udp747jk%22;timeRange=2024-04-04T16:41:07.506058Z%2F2024-04-04T16:44:56.710499Z;cursorTimestamp=2024-04-04T16:41:11.848103Z?project=grpc-testing
I0404 16:46:50.527755 140340686102528 k8s_base_runner.py:1152] GCP Logs Explorer link to psm-grpc-server-wkoefrp2:
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-csm-server-20240404-1640-fq54f%22%0Alabels.%22k8s-pod%2Fdeployment_id%22%3D%22psm-grpc-server-wkoefrp2%22;timeRange=2024-04-04T16:40:53.492808Z%2F2024-04-04T16:46:50.527172Z;cursorTimestamp=2024-04-04T16:40:59.310219Z?project=grpc-testing
[ OK ] AffinityTest.test_session_affinity_policy_with_service_target
I0404 16:46:50.528012 140340686102528 base_testcase.py:67] ----- PSM Test Case PASSED: AffinityTest.test_session_affinity_policy_with_service_target -----

----------------------------------------------------------------------
Ran 3 tests in 1257.279s

OK
+ set +x
Failed test suites: 0


[ID: 7265131] Command finished after 2135 secs, exit value: 0


Warning: Permanently added 'localhost' (ED25519) to the list of known hosts.
[09:46:51 PDT] Collecting build artifacts from build VM
[09:46:54 PDT] Kokoro builder finished