Build/Test Explorer

TestFusion
Invocation status: Failed

Kokoro: grpc/core/master/macos/grpc_basictests_python

146 targets evaluated on for 23 min, 17 sec
by kokoro
3 Failed143 Passed

Showing build.log

Download
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.
[20:18:09 PDT] Transferring environment variable script to build VM
[20:18:10 PDT] Transferring kokoro_log_reader.py to build VM
[20:18:11 PDT] Transferring source code to build VM
[20:18:22 PDT] Executing build script on build VM



[ID: 4089877] Executing command via SSH:
export KOKORO_BUILD_NUMBER="21903"
export KOKORO_JOB_NAME="grpc/core/master/macos/grpc_basictests_python"
source /tmpfs/kokoro-env_vars.sh; if [[ -f /tmpfs/unlock-keychain.sh ]] ; then /tmpfs/unlock-keychain.sh ; rm -f /tmpfs/unlock-keychain.sh ; fi ; cd /tmpfs/src/ ; chmod 755 github/grpc/tools/internal_ci/macos/grpc_basictests_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" ; elif "$PYTHON_3_VERSION" -m pip install 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/macos/grpc_basictests_python.sh ; echo \${PIPESTATUS[0]} > /tmpfs/kokoro_build_exit_code ; rc=$? ; pkill -9 -i simulator ; pkill -9 -i bazel ; exit $rc ) > /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

+ export PREPARE_BUILD_INSTALL_DEPS_PYTHON=true
+ PREPARE_BUILD_INSTALL_DEPS_PYTHON=true
++ dirname github/grpc/tools/internal_ci/macos/grpc_basictests_python.sh
+ github/grpc/tools/internal_ci/macos/grpc_run_tests_matrix.sh
++ dirname github/grpc/tools/internal_ci/macos/grpc_run_tests_matrix.sh
+ source github/grpc/tools/internal_ci/macos/../../../tools/internal_ci/helper_scripts/move_src_tree_and_respawn_itself_rc
++ set -ex
+++ pwd
++ CURRENT_DIR=/tmpfs/src
++ CI_SCRIPT_RELATIVE_TO_SRC=github/grpc/tools/internal_ci/macos/grpc_run_tests_matrix.sh
++ '[' /tmpfs/src == /tmpfs/altsrc ']'
++ '[' /tmpfs/src == /tmpfs/src ']'
++ echo 'Moving workspace from /tmpfs/src to /tmpfs/altsrc and respawning the CI script.'
Moving workspace from /tmpfs/src to /tmpfs/altsrc and respawning the CI script.
++ exec bash -c 'set -ex; cd /tmpfs; mkdir -p altsrc; mv src/github altsrc; cd altsrc; exec '\''github/grpc/tools/internal_ci/macos/grpc_run_tests_matrix.sh'\'''
+ cd /tmpfs
+ mkdir -p altsrc
+ mv src/github altsrc
+ cd altsrc
+ exec github/grpc/tools/internal_ci/macos/grpc_run_tests_matrix.sh
++ dirname /tmpfs/altsrc/github/grpc/tools/internal_ci/macos/grpc_run_tests_matrix.sh
+ source /tmpfs/altsrc/github/grpc/tools/internal_ci/macos/../../../tools/internal_ci/helper_scripts/move_src_tree_and_respawn_itself_rc
++ set -ex
+++ pwd
++ CURRENT_DIR=/tmpfs/altsrc
++ CI_SCRIPT_RELATIVE_TO_SRC=/tmpfs/altsrc/github/grpc/tools/internal_ci/macos/grpc_run_tests_matrix.sh
++ '[' /tmpfs/altsrc == /tmpfs/altsrc ']'
++ echo 'Successfully respawned the CI script /tmpfs/altsrc/github/grpc/tools/internal_ci/macos/grpc_run_tests_matrix.sh under /tmpfs/altsrc.'
Successfully respawned the CI script /tmpfs/altsrc/github/grpc/tools/internal_ci/macos/grpc_run_tests_matrix.sh under /tmpfs/altsrc.
++ export GRPC_TEST_REPORT_BASE_DIR=/tmpfs/src/github/grpc
++ GRPC_TEST_REPORT_BASE_DIR=/tmpfs/src/github/grpc
++ dirname /tmpfs/altsrc/github/grpc/tools/internal_ci/macos/grpc_run_tests_matrix.sh
+ cd /tmpfs/altsrc/github/grpc/tools/internal_ci/macos/../../..
+ source tools/internal_ci/helper_scripts/prepare_build_macos_rc
++ echo 'kokoro pool: "macsvc-grpc"'
kokoro pool: "macsvc-grpc"
+++ sw_vers -productName
+++ sw_vers -productVersion
+++ sw_vers -buildVersion
++ echo 'OS: macOS 12.5 21G72'
OS: macOS 12.5 21G72
+++ sysctl -n machdep.cpu.brand_string
++ echo 'CPU type: Intel(R) Core(TM) i7-8700B CPU @ 3.20GHz'
CPU type: Intel(R) Core(TM) i7-8700B CPU @ 3.20GHz
+++ sysctl -n machdep.cpu.vendor
+++ uname -m
+++ sysctl -n machdep.cpu.family
+++ sysctl -n machdep.cpu.brand_string
++ echo 'CPU: GenuineIntel x86_64 Family 6 Model Intel(R) Core(TM) i7-8700B CPU @ 3.20GHz'
CPU: GenuineIntel x86_64 Family 6 Model Intel(R) Core(TM) i7-8700B CPU @ 3.20GHz
+++ sysctl -n hw.ncpu
++ echo 'CPU Cores: 4'
CPU Cores: 4
+++ sysctl -n hw.memsize
++ echo 'Memory: 17179869184'
Memory: 17179869184
+++ cat /VERSION
++ echo 'Kokoro image version: 20221213-1155monterey-MacService'
Kokoro image version: 20221213-1155monterey-MacService
++ mount
/dev/disk5s5s1 on / (apfs, sealed, local, read-only, journaled)
devfs on /dev (devfs, local, nobrowse)
/dev/disk5s4 on /System/Volumes/VM (apfs, local, noexec, journaled, noatime, nobrowse)
/dev/disk5s2 on /System/Volumes/Preboot (apfs, local, journaled, nobrowse)
/dev/disk5s6 on /System/Volumes/Update (apfs, local, journaled, nobrowse)
/dev/disk5s1 on /System/Volumes/Data (apfs, local, journaled, nobrowse)
map auto_home on /System/Volumes/Data/home (autofs, automounted, nobrowse)
/dev/disk0 on /Volumes/kokoro_ssh_scripts (cd9660, local, read-only)
/dev/disk2 on /Volumes/kokoro_scripts (cd9660, local, read-only)
/dev/disk6s1 on /Volumes/BuildData (apfs, local, journaled)
/dev/disk7 on /Volumes/ramdisk (hfs, local, nodev, nosuid, journaled)
++ df -h /tmpfs /
Filesystem Size Used Avail Capacity iused ifree %iused Mounted on
/dev/disk6s1 143Gi 577Mi 142Gi 1% 15019 1490786880 0% /Volumes/BuildData
/dev/disk5s5s1 230Gi 14Gi 139Gi 10% 502061 1458568560 0% /
++ launchctl limit maxfiles
maxfiles 500000 500000
++ ulimit -a
core file size (blocks, -c) 0
data seg size (kbytes, -d) unlimited
file size (blocks, -f) unlimited
max locked memory (kbytes, -l) unlimited
max memory size (kbytes, -m) unlimited
open files (-n) 500000
pipe size (512 bytes, -p) 1
stack size (kbytes, -s) 8192
cpu time (seconds, -t) unlimited
max user processes (-u) 2500
virtual memory (kbytes, -v) unlimited
++ export HOMEBREW_NO_AUTO_UPDATE=1
++ HOMEBREW_NO_AUTO_UPDATE=1
++ brew config
HOMEBREW_VERSION: 3.6.14
ORIGIN: https://github.com/Homebrew/brew
HEAD: 001bacee18c512657e1535dff757c8cfdaefc116
Last commit: 1 year, 9 months ago
Core tap ORIGIN: https://github.com/Homebrew/homebrew-core
Core tap HEAD: 8fbd4c5fe833516ca826d56eb5c6f4792cc5b899
Core tap last commit: 1 year, 9 months ago
Core tap branch: master
HOMEBREW_PREFIX: /usr/local
HOMEBREW_CASK_OPTS: []
HOMEBREW_MAKE_JOBS: 4
HOMEBREW_NO_AUTO_UPDATE: set
Homebrew Ruby: 2.6.8 => /System/Library/Frameworks/Ruby.framework/Versions/2.6/usr/bin/ruby
CPU: quad-core 64-bit penryn
Clang: 14.0.0 build 1400
Git: 2.38.1 => /usr/local/bin/git
Curl: 7.79.1 => /usr/bin/curl
macOS: 12.5-x86_64
CLT: 14.1.0.0.1.1666437224
Xcode: 14.1 => /Applications/Xcode_14.app/Contents/Developer
++ pip install --user google-api-python-client oauth2client six==1.16.0
Collecting google-api-python-client
Downloading google_api_python_client-2.143.0-py2.py3-none-any.whl (12.2 MB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 12.2/12.2 MB 43.0 MB/s eta 0:00:00
Collecting oauth2client
Downloading oauth2client-4.1.3-py2.py3-none-any.whl (98 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 98.2/98.2 KB 1.7 MB/s eta 0:00:00
Requirement already satisfied: six==1.16.0 in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (1.16.0)
Collecting google-api-core!=2.0.*,!=2.1.*,!=2.2.*,!=2.3.0,<3.0.0.dev0,>=1.31.5
Downloading google_api_core-2.19.2-py3-none-any.whl (139 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 139.4/139.4 KB 3.8 MB/s eta 0:00:00
Requirement already satisfied: httplib2<1.dev0,>=0.19.0 in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (from google-api-python-client) (0.21.0)
Collecting google-auth-httplib2<1.0.0,>=0.2.0
Downloading google_auth_httplib2-0.2.0-py2.py3-none-any.whl (9.3 kB)
Requirement already satisfied: google-auth!=2.24.0,!=2.25.0,<3.0.0.dev0,>=1.32.0 in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (from google-api-python-client) (2.15.0)
Collecting uritemplate<5,>=3.0.1
Downloading uritemplate-4.1.1-py2.py3-none-any.whl (10 kB)
Requirement already satisfied: pyasn1-modules>=0.0.5 in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (from oauth2client) (0.2.8)
Requirement already satisfied: rsa>=3.1.4 in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (from oauth2client) (4.9)
Requirement already satisfied: pyasn1>=0.1.7 in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (from oauth2client) (0.4.8)
Requirement already satisfied: requests<3.0.0.dev0,>=2.18.0 in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (from google-api-core!=2.0.*,!=2.1.*,!=2.2.*,!=2.3.0,<3.0.0.dev0,>=1.31.5->google-api-python-client) (2.28.1)
Collecting googleapis-common-protos<2.0.dev0,>=1.56.2
Downloading googleapis_common_protos-1.65.0-py2.py3-none-any.whl (220 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 220.9/220.9 KB 4.6 MB/s eta 0:00:00
Collecting protobuf!=3.20.0,!=3.20.1,!=4.21.0,!=4.21.1,!=4.21.2,!=4.21.3,!=4.21.4,!=4.21.5,<6.0.0.dev0,>=3.19.5
Downloading protobuf-5.28.0-cp38-abi3-macosx_10_9_universal2.whl (414 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 414.7/414.7 KB 8.9 MB/s eta 0:00:00
Collecting proto-plus<2.0.0dev,>=1.22.3
Downloading proto_plus-1.24.0-py3-none-any.whl (50 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 50.1/50.1 KB 995.0 kB/s eta 0:00:00
Requirement already satisfied: cachetools<6.0,>=2.0.0 in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (from google-auth!=2.24.0,!=2.25.0,<3.0.0.dev0,>=1.32.0->google-api-python-client) (5.2.0)
Requirement already satisfied: pyparsing!=3.0.0,!=3.0.1,!=3.0.2,!=3.0.3,<4,>=2.4.2 in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (from httplib2<1.dev0,>=0.19.0->google-api-python-client) (3.0.9)
Requirement already satisfied: charset-normalizer<3,>=2 in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (from requests<3.0.0.dev0,>=2.18.0->google-api-core!=2.0.*,!=2.1.*,!=2.2.*,!=2.3.0,<3.0.0.dev0,>=1.31.5->google-api-python-client) (2.1.1)
Requirement already satisfied: urllib3<1.27,>=1.21.1 in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (from requests<3.0.0.dev0,>=2.18.0->google-api-core!=2.0.*,!=2.1.*,!=2.2.*,!=2.3.0,<3.0.0.dev0,>=1.31.5->google-api-python-client) (1.26.13)
Requirement already satisfied: idna<4,>=2.5 in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (from requests<3.0.0.dev0,>=2.18.0->google-api-core!=2.0.*,!=2.1.*,!=2.2.*,!=2.3.0,<3.0.0.dev0,>=1.31.5->google-api-python-client) (3.4)
Requirement already satisfied: certifi>=2017.4.17 in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (from requests<3.0.0.dev0,>=2.18.0->google-api-core!=2.0.*,!=2.1.*,!=2.2.*,!=2.3.0,<3.0.0.dev0,>=1.31.5->google-api-python-client) (2022.12.7)
Installing collected packages: uritemplate, protobuf, proto-plus, oauth2client, googleapis-common-protos, google-auth-httplib2, google-api-core, google-api-python-client
Successfully installed google-api-core-2.19.2 google-api-python-client-2.143.0 google-auth-httplib2-0.2.0 googleapis-common-protos-1.65.0 oauth2client-4.1.3 proto-plus-1.24.0 protobuf-5.28.0 uritemplate-4.1.1
WARNING: You are using pip version 22.0.4; however, version 24.2 is available.
You should consider upgrading via the '/Users/kbuilder/.pyenv/versions/3.10.3/bin/python3.10 -m pip install --upgrade pip' command.
++ export GOOGLE_APPLICATION_CREDENTIALS=/tmpfs/src/gfile/GrpcTesting-d0eeee2db331.json
++ GOOGLE_APPLICATION_CREDENTIALS=/tmpfs/src/gfile/GrpcTesting-d0eeee2db331.json
++++ dirname tools/internal_ci/helper_scripts/prepare_build_macos_rc
+++ cd tools/internal_ci/helper_scripts
+++ pwd
++ DIR=/tmpfs/altsrc/github/grpc/tools/internal_ci/helper_scripts
++ '[' -n '' ']'
++ '[' '' == true ']'
++ '[' '' == true ']'
++ '[' true == true ']'
++ pip install --user -r /tmpfs/altsrc/github/grpc/tools/internal_ci/helper_scripts/requirements.macos.txt
Requirement already satisfied: cython<3.0.0rc1 in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (from -r /tmpfs/altsrc/github/grpc/tools/internal_ci/helper_scripts/requirements.macos.txt (line 1)) (0.29.32)
Collecting cryptography==3.4.6
Downloading cryptography-3.4.6-cp36-abi3-macosx_10_10_x86_64.whl (2.0 MB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 2.0/2.0 MB 11.8 MB/s eta 0:00:00
Collecting PyJWT==2.0.1
Downloading PyJWT-2.0.1-py3-none-any.whl (15 kB)
Collecting pyOpenSSL==20.0.1
Downloading pyOpenSSL-20.0.1-py2.py3-none-any.whl (54 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 54.1/54.1 KB 1.0 MB/s eta 0:00:00
Requirement already satisfied: PyYAML==6.0 in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (from -r /tmpfs/altsrc/github/grpc/tools/internal_ci/helper_scripts/requirements.macos.txt (line 5)) (6.0)
Collecting requests==2.32.2
Downloading requests-2.32.2-py3-none-any.whl (63 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 63.9/63.9 KB 1.5 MB/s eta 0:00:00
Requirement already satisfied: cffi>=1.12 in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (from cryptography==3.4.6->-r /tmpfs/altsrc/github/grpc/tools/internal_ci/helper_scripts/requirements.macos.txt (line 2)) (1.15.1)
Requirement already satisfied: six>=1.5.2 in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (from pyOpenSSL==20.0.1->-r /tmpfs/altsrc/github/grpc/tools/internal_ci/helper_scripts/requirements.macos.txt (line 4)) (1.16.0)
Requirement already satisfied: idna<4,>=2.5 in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (from requests==2.32.2->-r /tmpfs/altsrc/github/grpc/tools/internal_ci/helper_scripts/requirements.macos.txt (line 6)) (3.4)
Requirement already satisfied: urllib3<3,>=1.21.1 in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (from requests==2.32.2->-r /tmpfs/altsrc/github/grpc/tools/internal_ci/helper_scripts/requirements.macos.txt (line 6)) (1.26.13)
Requirement already satisfied: charset-normalizer<4,>=2 in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (from requests==2.32.2->-r /tmpfs/altsrc/github/grpc/tools/internal_ci/helper_scripts/requirements.macos.txt (line 6)) (2.1.1)
Requirement already satisfied: certifi>=2017.4.17 in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (from requests==2.32.2->-r /tmpfs/altsrc/github/grpc/tools/internal_ci/helper_scripts/requirements.macos.txt (line 6)) (2022.12.7)
Requirement already satisfied: pycparser in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (from cffi>=1.12->cryptography==3.4.6->-r /tmpfs/altsrc/github/grpc/tools/internal_ci/helper_scripts/requirements.macos.txt (line 2)) (2.21)
Installing collected packages: requests, PyJWT, cryptography, pyOpenSSL
Successfully installed PyJWT-2.0.1 cryptography-3.4.6 pyOpenSSL-20.0.1 requests-2.32.2
WARNING: You are using pip version 22.0.4; however, version 24.2 is available.
You should consider upgrading via the '/Users/kbuilder/.pyenv/versions/3.10.3/bin/python3.10 -m pip install --upgrade pip' command.

real 0m3.852s
user 0m2.034s
sys 0m0.262s
++ pip install --user --upgrade virtualenv Mako tox setuptools==44.1.1 twisted
Requirement already satisfied: virtualenv in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (20.17.1)
Collecting virtualenv
Downloading virtualenv-20.26.3-py3-none-any.whl (5.7 MB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 5.7/5.7 MB 17.9 MB/s eta 0:00:00
Collecting Mako
Downloading Mako-1.3.5-py3-none-any.whl (78 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 78.6/78.6 KB 1.8 MB/s eta 0:00:00
Requirement already satisfied: tox in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (4.0.3)
Collecting tox
Downloading tox-4.18.0-py3-none-any.whl (156 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 156.7/156.7 KB 4.0 MB/s eta 0:00:00
Collecting setuptools==44.1.1
Using cached setuptools-44.1.1-py2.py3-none-any.whl (583 kB)
Collecting twisted
Downloading twisted-24.7.0-py3-none-any.whl (3.2 MB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 3.2/3.2 MB 30.1 MB/s eta 0:00:00
Collecting filelock<4,>=3.12.2
Downloading filelock-3.15.4-py3-none-any.whl (16 kB)
Collecting platformdirs<5,>=3.9.1
Downloading platformdirs-4.2.2-py3-none-any.whl (18 kB)
Collecting distlib<1,>=0.3.7
Downloading distlib-0.3.8-py2.py3-none-any.whl (468 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 468.9/468.9 KB 12.5 MB/s eta 0:00:00
Collecting MarkupSafe>=0.9.2
Downloading MarkupSafe-2.1.5-cp310-cp310-macosx_10_9_x86_64.whl (14 kB)
Collecting chardet>=5.2
Downloading chardet-5.2.0-py3-none-any.whl (199 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 199.4/199.4 KB 4.6 MB/s eta 0:00:00
Collecting cachetools>=5.4
Downloading cachetools-5.5.0-py3-none-any.whl (9.5 kB)
Requirement already satisfied: colorama>=0.4.6 in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (from tox) (0.4.6)
Collecting packaging>=24.1
Downloading packaging-24.1-py3-none-any.whl (53 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 54.0/54.0 KB 1.9 MB/s eta 0:00:00
Collecting pyproject-api>=1.7.1
Downloading pyproject_api-1.7.1-py3-none-any.whl (13 kB)
Collecting pluggy>=1.5
Downloading pluggy-1.5.0-py3-none-any.whl (20 kB)
Requirement already satisfied: tomli>=2.0.1 in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (from tox) (2.0.1)
Collecting zope-interface>=5
Downloading zope.interface-7.0.3-cp310-cp310-macosx_10_9_x86_64.whl (207 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 207.9/207.9 KB 2.7 MB/s eta 0:00:00
Collecting hyperlink>=17.1.1
Downloading hyperlink-21.0.0-py2.py3-none-any.whl (74 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 74.6/74.6 KB 2.2 MB/s eta 0:00:00
Collecting attrs>=21.3.0
Downloading attrs-24.2.0-py3-none-any.whl (63 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 63.0/63.0 KB 1.6 MB/s eta 0:00:00
Collecting automat>=0.8.0
Downloading Automat-24.8.1-py3-none-any.whl (42 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 42.6/42.6 KB 927.1 kB/s eta 0:00:00
Collecting incremental>=24.7.0
Downloading incremental-24.7.2-py3-none-any.whl (20 kB)
Collecting typing-extensions>=4.2.0
Downloading typing_extensions-4.12.2-py3-none-any.whl (37 kB)
Collecting constantly>=15.1
Downloading constantly-23.10.4-py3-none-any.whl (13 kB)
Requirement already satisfied: idna>=2.5 in /Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/site-packages (from hyperlink>=17.1.1->twisted) (3.4)
Collecting incremental>=24.7.0
Downloading incremental-24.7.1-py3-none-any.whl (20 kB)
INFO: pip is looking at multiple versions of hyperlink to determine which version is compatible with other requirements. This could take a while.
Collecting hyperlink>=17.1.1
Downloading hyperlink-20.0.1-py2.py3-none-any.whl (48 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 48.4/48.4 KB 1.6 MB/s eta 0:00:00
INFO: pip is looking at multiple versions of filelock to determine which version is compatible with other requirements. This could take a while.
INFO: pip is looking at multiple versions of distlib to determine which version is compatible with other requirements. This could take a while.
Collecting distlib<1,>=0.3.7
Downloading distlib-0.3.7-py2.py3-none-any.whl (468 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 468.9/468.9 KB 9.8 MB/s eta 0:00:00
INFO: pip is looking at multiple versions of constantly to determine which version is compatible with other requirements. This could take a while.
Collecting constantly>=15.1
Downloading constantly-15.1.0-py2.py3-none-any.whl (7.9 kB)
INFO: pip is looking at multiple versions of colorama to determine which version is compatible with other requirements. This could take a while.
Collecting colorama>=0.4.6
Downloading colorama-0.4.6-py2.py3-none-any.whl (25 kB)
INFO: pip is looking at multiple versions of chardet to determine which version is compatible with other requirements. This could take a while.
INFO: pip is looking at multiple versions of cachetools to determine which version is compatible with other requirements. This could take a while.
Collecting cachetools>=5.4
Downloading cachetools-5.4.0-py3-none-any.whl (9.5 kB)
INFO: pip is looking at multiple versions of automat to determine which version is compatible with other requirements. This could take a while.
Collecting automat>=0.8.0
Downloading Automat-22.10.0-py2.py3-none-any.whl (26 kB)
INFO: pip is looking at multiple versions of attrs to determine which version is compatible with other requirements. This could take a while.
Collecting attrs>=21.3.0
Downloading attrs-24.1.0-py3-none-any.whl (63 kB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 63.9/63.9 KB 2.9 MB/s eta 0:00:00
INFO: pip is looking at multiple versions of twisted to determine which version is compatible with other requirements. This could take a while.
Collecting twisted
Downloading twisted-24.3.0-py3-none-any.whl (3.2 MB)
━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 3.2/3.2 MB 27.5 MB/s eta 0:00:00
Collecting incremental>=22.10.0
Downloading incremental-22.10.0-py2.py3-none-any.whl (16 kB)
Installing collected packages: incremental, distlib, typing-extensions, setuptools, pluggy, platformdirs, packaging, MarkupSafe, hyperlink, filelock, constantly, chardet, cachetools, automat, attrs, zope-interface, virtualenv, pyproject-api, Mako, twisted, tox
WARNING: The scripts easy_install and easy_install-3.10 are installed in '/Users/kbuilder/.local/bin' which is not on PATH.
Consider adding this directory to PATH or, if you prefer to suppress this warning, use --no-warn-script-location.
NOTE: The current PATH contains path(s) starting with `~`, which may not be expanded by all applications.
WARNING: The script chardetect is installed in '/Users/kbuilder/.local/bin' which is not on PATH.
Consider adding this directory to PATH or, if you prefer to suppress this warning, use --no-warn-script-location.
NOTE: The current PATH contains path(s) starting with `~`, which may not be expanded by all applications.
WARNING: The script automat-visualize is installed in '/Users/kbuilder/.local/bin' which is not on PATH.
Consider adding this directory to PATH or, if you prefer to suppress this warning, use --no-warn-script-location.
NOTE: The current PATH contains path(s) starting with `~`, which may not be expanded by all applications.
WARNING: The script virtualenv is installed in '/Users/kbuilder/.local/bin' which is not on PATH.
Consider adding this directory to PATH or, if you prefer to suppress this warning, use --no-warn-script-location.
NOTE: The current PATH contains path(s) starting with `~`, which may not be expanded by all applications.
WARNING: The script mako-render is installed in '/Users/kbuilder/.local/bin' which is not on PATH.
Consider adding this directory to PATH or, if you prefer to suppress this warning, use --no-warn-script-location.
NOTE: The current PATH contains path(s) starting with `~`, which may not be expanded by all applications.
WARNING: The scripts cftp, ckeygen, conch, mailmail, pyhtmlizer, tkconch, trial, twist and twistd are installed in '/Users/kbuilder/.local/bin' which is not on PATH.
Consider adding this directory to PATH or, if you prefer to suppress this warning, use --no-warn-script-location.
NOTE: The current PATH contains path(s) starting with `~`, which may not be expanded by all applications.
WARNING: The script tox is installed in '/Users/kbuilder/.local/bin' which is not on PATH.
Consider adding this directory to PATH or, if you prefer to suppress this warning, use --no-warn-script-location.
NOTE: The current PATH contains path(s) starting with `~`, which may not be expanded by all applications.
Successfully installed Mako-1.3.5 MarkupSafe-2.1.5 attrs-24.2.0 automat-24.8.1 cachetools-5.5.0 chardet-5.2.0 constantly-23.10.4 distlib-0.3.8 filelock-3.15.4 hyperlink-21.0.0 incremental-22.10.0 packaging-24.1 platformdirs-4.2.2 pluggy-1.5.0 pyproject-api-1.7.1 setuptools-44.1.1 tox-4.18.0 twisted-24.3.0 typing-extensions-4.12.2 virtualenv-20.26.3 zope-interface-7.0.3
WARNING: You are using pip version 22.0.4; however, version 24.2 is available.
You should consider upgrading via the '/Users/kbuilder/.pyenv/versions/3.10.3/bin/python3.10 -m pip install --upgrade pip' command.

real 0m13.058s
user 0m6.865s
sys 0m1.103s
++ curl -O https://www.python.org/ftp/python/3.7.9/python-3.7.9-macosx10.9.pkg
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0100 27.9M 100 27.9M 0 0 102M 0 --:--:-- --:--:-- --:--:-- 104M

real 0m0.279s
user 0m0.042s
sys 0m0.096s
++ echo 'bf54a14eef23467991e8c7a88c7307762e484c024a94ec1ee292ac1db3d41fc9 python-3.7.9-macosx10.9.pkg'
++ shasum -c /tmp/python_installer_checksum.sha256
python-3.7.9-macosx10.9.pkg: OK
++ sudo installer -pkg ./python-3.7.9-macosx10.9.pkg -target /
installer: Package name is Python
installer: Installing at base path /
installer: The install was successful.

real 0m23.179s
user 0m0.425s
sys 0m0.191s
++ python3.7 --version
Python 3.7.9
++ curl -O https://www.python.org/ftp/python/3.8.10/python-3.8.10-macosx10.9.pkg
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0100 28.5M 100 28.5M 0 0 139M 0 --:--:-- --:--:-- --:--:-- 144M

real 0m0.212s
user 0m0.046s
sys 0m0.111s
++ echo '4c65bc7534d5f07edacbe0fbd609b5734dbf3ac02f5444f9bd97963d589d8afd python-3.8.10-macosx10.9.pkg'
++ shasum -c /tmp/python_installer_checksum.sha256
python-3.8.10-macosx10.9.pkg: OK
++ sudo installer -pkg ./python-3.8.10-macosx10.9.pkg -target /
installer: Package name is Python
installer: Upgrading at base path /
installer: The upgrade was successful.

real 0m16.904s
user 0m0.418s
sys 0m0.198s
++ python3.8 --version
Python 3.8.10
++ '[' '!' -f /usr/local/bin/python3.9 ']'
++ curl -O https://www.python.org/ftp/python/3.9.10/python-3.9.10-macosx10.9.pkg
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0100 28.9M 100 28.9M 0 0 179M 0 --:--:-- --:--:-- --:--:-- 185M

real 0m0.168s
user 0m0.043s
sys 0m0.100s
++ echo '732bc5c95ae127dfb6fb1bcf683509ad20c558152b63b8d5f651246f6bdfc8da python-3.9.10-macosx10.9.pkg'
++ shasum -c /tmp/python_installer_checksum.sha256
python-3.9.10-macosx10.9.pkg: OK
++ sudo installer -pkg ./python-3.9.10-macosx10.9.pkg -target /
installer: Package name is Python
installer: Upgrading at base path /
installer: The upgrade was successful.

real 0m17.908s
user 0m0.423s
sys 0m0.196s
++ '[' '!' -f /usr/local/bin/python3.10 ']'
++ '[' '!' -f /usr/local/bin/python3.11 ']'
++ curl -O https://www.python.org/ftp/python/3.11.0/python-3.11.0rc1-macos11.pkg
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0 0 40.5M 0 39649 0 0 547k 0 0:01:15 --:--:-- 0:01:15 577k100 40.5M 100 40.5M 0 0 126M 0 --:--:-- --:--:-- --:--:-- 127M

real 0m0.328s
user 0m0.055s
sys 0m0.133s
++ echo 'eec3f817797b1d61f48f29b96ac0443ea19f3170 python-3.11.0rc1-macos11.pkg'
++ shasum -c /tmp/python_installer_checksum.sha256
python-3.11.0rc1-macos11.pkg: OK
++ sudo installer -pkg ./python-3.11.0rc1-macos11.pkg -target /
installer: Package name is Python
installer: Upgrading at base path /
installer: The upgrade was successful.

real 0m21.959s
user 0m0.463s
sys 0m0.207s
++ '[' '!' -f /usr/local/bin/python3.12 ']'
++ curl -O https://www.python.org/ftp/python/3.12.0/python-3.12.0rc2-macos11.pkg
% Total % Received % Xferd Average Speed Time Time Time Current
Dload Upload Total Spent Left Speed
0 0 0 0 0 0 0 0 --:--:-- --:--:-- --:--:-- 0100 43.2M 100 43.2M 0 0 124M 0 --:--:-- --:--:-- --:--:-- 127M

real 0m0.354s
user 0m0.059s
sys 0m0.140s
++ echo 'e5dc5511b604b501b892991d257d117bb5757437 python-3.12.0rc2-macos11.pkg'
++ shasum -c /tmp/python_installer_checksum.sha256
python-3.12.0rc2-macos11.pkg: OK
++ sudo installer -pkg ./python-3.12.0rc2-macos11.pkg -target /
installer: Package name is Python
installer: Upgrading at base path /
installer: The upgrade was successful.

real 0m20.974s
user 0m0.409s
sys 0m0.184s
++ '[' '' == true ']'
++ '[' '' == true ']'
++ date
Wed Sep 4 20:20:41 PDT 2024
++ git submodule update --init
Submodule 'third_party/abseil-cpp' (https://github.com/abseil/abseil-cpp.git) registered for path 'third_party/abseil-cpp'
Submodule 'third_party/benchmark' (https://github.com/google/benchmark) registered for path 'third_party/benchmark'
Submodule 'third_party/bloaty' (https://github.com/google/bloaty.git) registered for path 'third_party/bloaty'
Submodule 'third_party/boringssl-with-bazel' (https://github.com/google/boringssl.git) registered for path 'third_party/boringssl-with-bazel'
Submodule 'third_party/cares/cares' (https://github.com/c-ares/c-ares.git) registered for path 'third_party/cares/cares'
Submodule 'third_party/envoy-api' (https://github.com/envoyproxy/data-plane-api.git) registered for path 'third_party/envoy-api'
Submodule 'third_party/googleapis' (https://github.com/googleapis/googleapis.git) registered for path 'third_party/googleapis'
Submodule 'third_party/googletest' (https://github.com/google/googletest.git) registered for path 'third_party/googletest'
Submodule 'third_party/opencensus-proto' (https://github.com/census-instrumentation/opencensus-proto.git) registered for path 'third_party/opencensus-proto'
Submodule 'third_party/opentelemetry' (https://github.com/open-telemetry/opentelemetry-proto.git) registered for path 'third_party/opentelemetry'
Submodule 'third_party/opentelemetry-cpp' (https://github.com/open-telemetry/opentelemetry-cpp) registered for path 'third_party/opentelemetry-cpp'
Submodule 'third_party/protobuf' (https://github.com/protocolbuffers/protobuf.git) registered for path 'third_party/protobuf'
Submodule 'third_party/protoc-gen-validate' (https://github.com/envoyproxy/protoc-gen-validate.git) registered for path 'third_party/protoc-gen-validate'
Submodule 'third_party/re2' (https://github.com/google/re2.git) registered for path 'third_party/re2'
Submodule 'third_party/xds' (https://github.com/cncf/xds.git) registered for path 'third_party/xds'
Submodule 'third_party/zlib' (https://github.com/madler/zlib) registered for path 'third_party/zlib'
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/third_party/abseil-cpp'...
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/third_party/benchmark'...
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/third_party/bloaty'...
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/third_party/boringssl-with-bazel'...
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/third_party/cares/cares'...
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/third_party/envoy-api'...
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/third_party/googleapis'...
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/third_party/googletest'...
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/third_party/opencensus-proto'...
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/third_party/opentelemetry'...
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/third_party/opentelemetry-cpp'...
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/third_party/protobuf'...
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/third_party/protoc-gen-validate'...
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/third_party/re2'...
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/third_party/xds'...
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/third_party/zlib'...
Submodule path 'third_party/abseil-cpp': checked out '4a2c63365eff8823a5221db86ef490e828306f9d'
Submodule path 'third_party/benchmark': checked out '344117638c8ff7e239044fd0fa7085839fc03021'
Submodule path 'third_party/bloaty': checked out '60209eb1ccc34d5deefb002d1b7f37545204f7f2'
Submodule path 'third_party/boringssl-with-bazel': checked out '16c8d3db1af20fcc04b5190b25242aadcb1fbb30'
Submodule path 'third_party/cares/cares': checked out '6360e96b5cf8e5980c887ce58ef727e53d77243a'
Submodule path 'third_party/envoy-api': checked out 'f8b75d1efa92bbf534596a013d9ca5873f79dd30'
Submodule path 'third_party/googleapis': checked out 'fe8ba054ad4f7eca946c2d14a63c3f07c0b586a0'
Submodule path 'third_party/googletest': checked out '2dd1c131950043a8ad5ab0d2dda0e0970596586a'
Submodule path 'third_party/opencensus-proto': checked out '4aa53e15cbf1a47bc9087e6cfdca214c1eea4e89'
Submodule path 'third_party/opentelemetry': checked out '60fa8754d890b5c55949a8c68dcfd7ab5c2395df'
Submodule path 'third_party/opentelemetry-cpp': checked out '4bd64c9a336fd438d6c4c9dad2e6b61b0585311f'
Submodule path 'third_party/protobuf': checked out '63def39e881afa496502d9c410f4ea948e59490d'
Submodule path 'third_party/protoc-gen-validate': checked out 'fab737efbb4b4d03e7c771393708f75594b121e4'
Submodule path 'third_party/re2': checked out '0c5616df9c0aaa44c9440d87422012423d91c7d1'
Submodule path 'third_party/xds': checked out '3a472e524827f72d1ad621c4983dd5af54c46776'
Submodule path 'third_party/zlib': checked out '09155eaa2f9270dc4ed1fa13e2b4b2613e6e4851'

real 0m52.178s
user 1m2.610s
sys 0m18.033s
+ tools/run_tests/run_tests_matrix.py -f basictests macos python -j 1 --inner_jobs 4 --bq_result_table aggregate_results
2024-09-04 20:21:33,947 START: Running test matrix.
IMPORTANT: The changes you are testing need to be locally committed
because only the committed changes in the current branch will be
copied to the docker environment or into subworkspaces.
Will run these tests:
run_tests_python_macos_opt_native: "bash tools/run_tests/helper_scripts/run_tests_in_workspace.sh -t -j 4 -x run_tests/python_macos_opt_native/sponge_log.xml --report_suite_name python_macos_opt_native -l python -c opt --iomgr_platform native --bq_result_table aggregate_results --measure_cpu_costs --report_multi_target"

2024-09-04 20:21:33,947 START: run_tests_python_macos_opt_native
2024-09-04 20:36:44,670 ++ dirname tools/run_tests/helper_scripts/run_tests_in_workspace.sh
+ cd tools/run_tests/helper_scripts/../../..
++ pwd
+ repo_root=/tmpfs/altsrc/github/grpc
+ export repo_root
+ rm -rf workspace_python_macos_opt_native
+ git clone . workspace_python_macos_opt_native
Cloning into 'workspace_python_macos_opt_native'...
done.
Updating files: 31% (3912/12288)
Updating files: 32% (3933/12288)
Updating files: 33% (4056/12288)
Updating files: 34% (4178/12288)
Updating files: 35% (4301/12288)
Updating files: 36% (4424/12288)
Updating files: 37% (4547/12288)
Updating files: 38% (4670/12288)
Updating files: 39% (4793/12288)
Updating files: 40% (4916/12288)
Updating files: 41% (5039/12288)
Updating files: 42% (5161/12288)
Updating files: 43% (5284/12288)
Updating files: 44% (5407/12288)
Updating files: 45% (5530/12288)
Updating files: 46% (5653/12288)
Updating files: 47% (5776/12288)
Updating files: 48% (5899/12288)
Updating files: 49% (6022/12288)
Updating files: 50% (6144/12288)
Updating files: 51% (6267/12288)
Updating files: 52% (6390/12288)
Updating files: 53% (6513/12288)
Updating files: 54% (6636/12288)
Updating files: 55% (6759/12288)
Updating files: 56% (6882/12288)
Updating files: 57% (7005/12288)
Updating files: 58% (7128/12288)
Updating files: 59% (7250/12288)
Updating files: 60% (7373/12288)
Updating files: 61% (7496/12288)
Updating files: 62% (7619/12288)
Updating files: 63% (7742/12288)
Updating files: 64% (7865/12288)
Updating files: 65% (7988/12288)
Updating files: 66% (8111/12288)
Updating files: 67% (8233/12288)
Updating files: 68% (8356/12288)
Updating files: 69% (8479/12288)
Updating files: 70% (8602/12288)
Updating files: 71% (8725/12288)
Updating files: 72% (8848/12288)
Updating files: 73% (8971/12288)
Updating files: 74% (9094/12288)
Updating files: 75% (9216/12288)
Updating files: 75% (9310/12288)
Updating files: 76% (9339/12288)
Updating files: 77% (9462/12288)
Updating files: 78% (9585/12288)
Updating files: 79% (9708/12288)
Updating files: 80% (9831/12288)
Updating files: 81% (9954/12288)
Updating files: 82% (10077/12288)
Updating files: 83% (10200/12288)
Updating files: 84% (10322/12288)
Updating files: 85% (10445/12288)
Updating files: 86% (10568/12288)
Updating files: 87% (10691/12288)
Updating files: 88% (10814/12288)
Updating files: 89% (10937/12288)
Updating files: 90% (11060/12288)
Updating files: 91% (11183/12288)
Updating files: 92% (11305/12288)
Updating files: 93% (11428/12288)
Updating files: 94% (11551/12288)
Updating files: 95% (11674/12288)
Updating files: 96% (11797/12288)
Updating files: 97% (11920/12288)
Updating files: 98% (12043/12288)
Updating files: 99% (12166/12288)
Updating files: 100% (12288/12288)
Updating files: 100% (12288/12288), done.
+ git submodule foreach 'cd "${repo_root}/${WORKSPACE_NAME}" \
&& git submodule update --init --reference ${repo_root}/${name} ${name}'
Entering 'third_party/abseil-cpp'
Submodule 'third_party/abseil-cpp' (https://github.com/abseil/abseil-cpp.git) registered for path 'third_party/abseil-cpp'
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/third_party/abseil-cpp'...
Submodule path 'third_party/abseil-cpp': checked out '4a2c63365eff8823a5221db86ef490e828306f9d'
Entering 'third_party/benchmark'
Submodule 'third_party/benchmark' (https://github.com/google/benchmark) registered for path 'third_party/benchmark'
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/third_party/benchmark'...
Submodule path 'third_party/benchmark': checked out '344117638c8ff7e239044fd0fa7085839fc03021'
Entering 'third_party/bloaty'
Submodule 'third_party/bloaty' (https://github.com/google/bloaty.git) registered for path 'third_party/bloaty'
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/third_party/bloaty'...
Submodule path 'third_party/bloaty': checked out '60209eb1ccc34d5deefb002d1b7f37545204f7f2'
Entering 'third_party/boringssl-with-bazel'
Submodule 'third_party/boringssl-with-bazel' (https://github.com/google/boringssl.git) registered for path 'third_party/boringssl-with-bazel'
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/third_party/boringssl-with-bazel'...
Submodule path 'third_party/boringssl-with-bazel': checked out '16c8d3db1af20fcc04b5190b25242aadcb1fbb30'
Entering 'third_party/cares/cares'
Submodule 'third_party/cares/cares' (https://github.com/c-ares/c-ares.git) registered for path 'third_party/cares/cares'
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/third_party/cares/cares'...
Submodule path 'third_party/cares/cares': checked out '6360e96b5cf8e5980c887ce58ef727e53d77243a'
Entering 'third_party/envoy-api'
Submodule 'third_party/envoy-api' (https://github.com/envoyproxy/data-plane-api.git) registered for path 'third_party/envoy-api'
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/third_party/envoy-api'...
Submodule path 'third_party/envoy-api': checked out 'f8b75d1efa92bbf534596a013d9ca5873f79dd30'
Entering 'third_party/googleapis'
Submodule 'third_party/googleapis' (https://github.com/googleapis/googleapis.git) registered for path 'third_party/googleapis'
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/third_party/googleapis'...
Submodule path 'third_party/googleapis': checked out 'fe8ba054ad4f7eca946c2d14a63c3f07c0b586a0'
Entering 'third_party/googletest'
Submodule 'third_party/googletest' (https://github.com/google/googletest.git) registered for path 'third_party/googletest'
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/third_party/googletest'...
Submodule path 'third_party/googletest': checked out '2dd1c131950043a8ad5ab0d2dda0e0970596586a'
Entering 'third_party/opencensus-proto'
Submodule 'third_party/opencensus-proto' (https://github.com/census-instrumentation/opencensus-proto.git) registered for path 'third_party/opencensus-proto'
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/third_party/opencensus-proto'...
Submodule path 'third_party/opencensus-proto': checked out '4aa53e15cbf1a47bc9087e6cfdca214c1eea4e89'
Entering 'third_party/opentelemetry'
Submodule 'third_party/opentelemetry' (https://github.com/open-telemetry/opentelemetry-proto.git) registered for path 'third_party/opentelemetry'
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/third_party/opentelemetry'...
Submodule path 'third_party/opentelemetry': checked out '60fa8754d890b5c55949a8c68dcfd7ab5c2395df'
Entering 'third_party/opentelemetry-cpp'
Submodule 'third_party/opentelemetry-cpp' (https://github.com/open-telemetry/opentelemetry-cpp) registered for path 'third_party/opentelemetry-cpp'
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/third_party/opentelemetry-cpp'...
Submodule path 'third_party/opentelemetry-cpp': checked out '4bd64c9a336fd438d6c4c9dad2e6b61b0585311f'
Entering 'third_party/protobuf'
Submodule 'third_party/protobuf' (https://github.com/protocolbuffers/protobuf.git) registered for path 'third_party/protobuf'
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/third_party/protobuf'...
Submodule path 'third_party/protobuf': checked out '63def39e881afa496502d9c410f4ea948e59490d'
Entering 'third_party/protoc-gen-validate'
Submodule 'third_party/protoc-gen-validate' (https://github.com/envoyproxy/protoc-gen-validate.git) registered for path 'third_party/protoc-gen-validate'
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/third_party/protoc-gen-validate'...
Submodule path 'third_party/protoc-gen-validate': checked out 'fab737efbb4b4d03e7c771393708f75594b121e4'
Entering 'third_party/re2'
Submodule 'third_party/re2' (https://github.com/google/re2.git) registered for path 'third_party/re2'
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/third_party/re2'...
Submodule path 'third_party/re2': checked out '0c5616df9c0aaa44c9440d87422012423d91c7d1'
Entering 'third_party/xds'
Submodule 'third_party/xds' (https://github.com/cncf/xds.git) registered for path 'third_party/xds'
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/third_party/xds'...
Submodule path 'third_party/xds': checked out '3a472e524827f72d1ad621c4983dd5af54c46776'
Entering 'third_party/zlib'
Submodule 'third_party/zlib' (https://github.com/madler/zlib) registered for path 'third_party/zlib'
Cloning into '/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/third_party/zlib'...
Submodule path 'third_party/zlib': checked out '09155eaa2f9270dc4ed1fa13e2b4b2613e6e4851'
+ echo 'Running run_tests.py in workspace workspace_python_macos_opt_native'
Running run_tests.py in workspace workspace_python_macos_opt_native
+ python3 workspace_python_macos_opt_native/tools/run_tests/run_tests.py -t -j 4 -x run_tests/python_macos_opt_native/sponge_log.xml --report_suite_name python_macos_opt_native -l python -c opt --iomgr_platform native --bq_result_table aggregate_results --measure_cpu_costs --report_multi_target
2024-09-04 20:21:47,488 START: /Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/tools/run_tests/helper_scripts/build_python.sh
2024-09-04 20:34:30,531 PASSED: /Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/tools/run_tests/helper_scripts/build_python.sh [time=763.0sec, retries=0:0; cpu_cost=3.4; estimated=1.0]
2024-09-04 20:34:30,545 failed to detect port server
Traceback (most recent call last):
File "/Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/urllib/request.py", line 1348, in do_open
h.request(req.get_method(), req.selector, req.data, headers,
File "/Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/http/client.py", line 1282, in request
self._send_request(method, url, body, headers, encode_chunked)
File "/Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/http/client.py", line 1328, in _send_request
self.endheaders(body, encode_chunked=encode_chunked)
File "/Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/http/client.py", line 1277, in endheaders
self._send_output(message_body, encode_chunked=encode_chunked)
File "/Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/http/client.py", line 1037, in _send_output
self.send(msg)
File "/Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/http/client.py", line 975, in send
self.connect()
File "/Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/http/client.py", line 941, in connect
self.sock = self._create_connection(
File "/Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/socket.py", line 845, in create_connection
raise err
File "/Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/socket.py", line 833, in create_connection
sock.connect(sa)
ConnectionRefusedError: [Errno 61] Connection refused

During handling of the above exception, another exception occurred:

Traceback (most recent call last):
File "/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/tools/run_tests/python_utils/start_port_server.py", line 41, in start_port_server
request.urlopen(
File "/Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/urllib/request.py", line 216, in urlopen
return opener.open(url, data, timeout)
File "/Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/urllib/request.py", line 519, in open
response = self._open(req, data)
File "/Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/urllib/request.py", line 536, in _open
result = self._call_chain(self.handle_open, protocol, protocol +
File "/Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/urllib/request.py", line 496, in _call_chain
result = func(*args)
File "/Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/urllib/request.py", line 1377, in http_open
return self.do_open(http.client.HTTPConnection, req)
File "/Users/kbuilder/.pyenv/versions/3.10.3/lib/python3.10/urllib/request.py", line 1351, in do_open
raise URLError(err)
urllib.error.URLError:
2024-09-04 20:34:30,573 starting port_server, with log file /var/folders/1d/z50_0t6s6fsb1yj3_svwklk80000gn/T/tmp5kppoj5m
2024-09-04 20:34:31,695 port server is up and ready
2024-09-04 20:34:31,697 START: py38.asyncio.tests_aio.unit.client_stream_stream_interceptor_test.TestStreamStreamClientInterceptor
2024-09-04 20:34:31,700 START: py38.native.tests.unit._server_ssl_cert_config_test.ServerSSLCertReloadTestWithClientAuth
2024-09-04 20:34:31,704 START: py38.native.tests.unit.beta._implementations_test.CallCredentialsTest
2024-09-04 20:34:31,708 START: py38.native.tests.unit._auth_context_test.AuthContextTest
2024-09-04 20:34:32,814 PASSED: py38.asyncio.tests_aio.unit.client_stream_stream_interceptor_test.TestStreamStreamClientInterceptor [time=1.1sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:34:32,815 START: py38.native.tests.unit._dns_resolver_test.DNSResolverTest
2024-09-04 20:34:32,956 PASSED: py38.native.tests.unit.beta._implementations_test.CallCredentialsTest [time=1.3sec, retries=0:0; cpu_cost=0.9; estimated=1.0]
2024-09-04 20:34:32,957 START: py38.native.tests.interop._secure_intraop_test.SecureIntraopTest
2024-09-04 20:34:33,018 PASSED: py38.native.tests.unit._auth_context_test.AuthContextTest [time=1.3sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:34:33,019 START: py38.native.tests.unit._channel_connectivity_test.ChannelConnectivityTest
2024-09-04 20:34:33,944 PASSED: py38.native.tests.unit._server_ssl_cert_config_test.ServerSSLCertReloadTestWithClientAuth [time=2.2sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:34:33,945 START: py38.native.tests.unit._channel_ready_future_test.ChannelReadyFutureTest
2024-09-04 20:34:34,195 PASSED: py38.native.tests.unit._dns_resolver_test.DNSResolverTest [time=1.4sec, retries=0:0; cpu_cost=0.9; estimated=1.0]
2024-09-04 20:34:34,196 START: py38.native.tests.protoc_plugin._split_definitions_test.SplitProtoProtoBeforeGrpcProtocStyleTest
2024-09-04 20:34:34,248 PASSED: py38.native.tests.interop._secure_intraop_test.SecureIntraopTest [time=1.3sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:34:34,249 START: py38.native.tests.unit._channel_args_test.ChannelArgsTest
2024-09-04 20:34:35,259 PASSED: py38.native.tests.protoc_plugin._split_definitions_test.SplitProtoProtoBeforeGrpcProtocStyleTest [time=1.1sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:34:35,259 START: py38.native.tests.unit._cython.cygrpc_test.TypeSmokeTest
2024-09-04 20:34:35,298 PASSED: py38.native.tests.unit._channel_args_test.ChannelArgsTest [time=1.0sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:34:35,307 START: py38.native.tests.unit._server_ssl_cert_config_test.ServerSSLCertReloadTestCertConfigReuse
2024-09-04 20:34:36,339 PASSED: py38.native.tests.unit._cython.cygrpc_test.TypeSmokeTest [time=1.1sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:34:36,340 START: py38.native.tests.unit.beta._beta_features_test.BetaFeaturesTest
2024-09-04 20:34:37,387 PASSED: py38.native.tests.unit._server_ssl_cert_config_test.ServerSSLCertReloadTestCertConfigReuse [time=2.1sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:34:37,388 START: py38.native.tests.unit.beta._implementations_test.ChannelCredentialsTest
2024-09-04 20:34:37,455 PASSED: py38.native.tests.unit.beta._beta_features_test.BetaFeaturesTest [time=1.1sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:34:37,456 START: py38.asyncio.tests_aio.unit.compression_test.TestCompression
2024-09-04 20:34:38,399 PASSED: py38.native.tests.unit.beta._implementations_test.ChannelCredentialsTest [time=1.0sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:34:38,400 START: py38.asyncio.tests_aio.unit.connectivity_test.TestConnectivityState
2024-09-04 20:34:38,604 PASSED: py38.asyncio.tests_aio.unit.compression_test.TestCompression [time=1.1sec, retries=0:0; cpu_cost=0.8; estimated=1.0]
2024-09-04 20:34:38,605 START: py38.xds_protos
2024-09-04 20:34:39,343 PASSED: py38.native.tests.unit._channel_ready_future_test.ChannelReadyFutureTest [time=5.4sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:34:39,344 START: py38.asyncio.tests_aio.unit.call_test.TestStreamStreamCall
2024-09-04 20:34:39,978 PASSED: py38.xds_protos [time=1.4sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:34:39,979 START: py38.native.tests.unit._version_test.VersionTest
2024-09-04 20:34:40,957 PASSED: py38.native.tests.unit._version_test.VersionTest [time=1.0sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:34:40,958 START: py38.asyncio.tests_aio.unit.client_unary_unary_interceptor_test.TestUnaryUnaryClientInterceptor
2024-09-04 20:34:42,460 PASSED: py38.asyncio.tests_aio.unit.call_test.TestStreamStreamCall [time=3.1sec, retries=0:0; cpu_cost=0.3; estimated=1.0]
2024-09-04 20:34:42,460 START: py38.native.tests.unit._utilities_test.UtilityTest
2024-09-04 20:34:42,889 PASSED: py38.asyncio.tests_aio.unit.client_unary_unary_interceptor_test.TestUnaryUnaryClientInterceptor [time=1.9sec, retries=0:0; cpu_cost=0.5; estimated=1.0]
2024-09-04 20:34:42,890 START: py38.native.tests.unit._xds_credentials_test.XdsCredentialsTest
2024-09-04 20:34:42,894 PASSED: py38.native.tests.unit._channel_connectivity_test.ChannelConnectivityTest [time=9.9sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:34:42,895 START: py38.native.tests.unit._cython._cancel_many_calls_test.CancelManyCallsTest
2024-09-04 20:34:43,450 PASSED: py38.native.tests.unit._utilities_test.UtilityTest [time=1.0sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:34:43,450 START: py38.native.tests.admin.admin_test.TestAdmin
2024-09-04 20:34:44,006 PASSED: py38.native.tests.unit._xds_credentials_test.XdsCredentialsTest [time=1.1sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:34:44,013 START: py38.asyncio.tests_aio.unit.client_unary_stream_interceptor_test.TestUnaryStreamClientInterceptor
2024-09-04 20:34:44,018 PASSED: py38.native.tests.unit._cython._cancel_many_calls_test.CancelManyCallsTest [time=1.1sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:34:44,019 START: py38.native.tests.unit._cython._no_messages_single_server_completion_queue_test.Test
2024-09-04 20:34:44,551 PASSED: py38.native.tests.admin.admin_test.TestAdmin [time=1.1sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:34:44,551 START: py38.native.tests.unit._rpc_part_1_test.RPCPart1Test
2024-09-04 20:34:45,397 PASSED: py38.asyncio.tests_aio.unit.client_unary_stream_interceptor_test.TestUnaryStreamClientInterceptor [time=1.4sec, retries=0:0; cpu_cost=0.8; estimated=1.0]
2024-09-04 20:34:45,398 START: py38.native.tests.unit._credentials_test.CredentialsTest
2024-09-04 20:34:46,549 PASSED: py38.native.tests.unit._credentials_test.CredentialsTest [time=1.2sec, retries=0:0; cpu_cost=0.9; estimated=1.0]
2024-09-04 20:34:46,550 START: py38.native.tests.protoc_plugin._python_plugin_test.ModuleMainTest
2024-09-04 20:34:47,492 ++ dirname /Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/tools/run_tests/helper_scripts/run_python.sh
+ cd /Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/tools/run_tests/helper_scripts/../../..
++ pwd
+ PYTHON=/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/py38/bin/python
++ pwd
+ ROOT=/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native
+ /Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/py38/bin/python /Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/src/python/grpcio_tests/setup.py test_aio
running test_aio
Running tests_aio.unit.connectivity_test.TestConnectivityState.test_normal_backend
WARNING: All log messages before absl::InitializeLog() is called are written to STDERR
W0000 00:00:1725507279.154238 96710 log.cc:112] Log level DEBUG is not suitable for production. Prefer WARNING or ERROR. However if you see this message in a debug environmenmt or test environmenmt it is safe to ignore this message.
Running tests_aio.unit.connectivity_test.TestConnectivityState.test_shutdown
Running tests_aio.unit.connectivity_test.TestConnectivityState.test_timeout
Running tests_aio.unit.connectivity_test.TestConnectivityState.test_unavailable_backend
Testing gRPC Python...
SUCCESS tests_aio.unit.connectivity_test.TestConnectivityState.test_normal_backend
SUCCESS tests_aio.unit.connectivity_test.TestConnectivityState.test_shutdown
SUCCESS tests_aio.unit.connectivity_test.TestConnectivityState.test_timeout
ERROR tests_aio.unit.connectivity_test.TestConnectivityState.test_unavailable_backend
4 tests finished:
3 successful
1 unsuccessful
0 skipped
0 expected failures
0 unexpected successes
Interrupted Tests:
[]

Errors/Failures:
tests_aio.unit.connectivity_test.TestConnectivityState.test_unavailable_backend
traceback:
Traceback (most recent call last):
File "/Library/Frameworks/Python.framework/Versions/3.8/lib/python3.8/unittest/case.py", line 60, in testPartExecutor
yield
File "/Library/Frameworks/Python.framework/Versions/3.8/lib/python3.8/unittest/case.py", line 676, in run
self._callTestMethod(testMethod)
File "/Library/Frameworks/Python.framework/Versions/3.8/lib/python3.8/unittest/case.py", line 633, in _callTestMethod
method()
File "/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/src/python/grpcio_tests/tests_aio/unit/_test_base.py", line 31, in wrapper
return loop.run_until_complete(f(*args, **kwargs))
File "/Library/Frameworks/Python.framework/Versions/3.8/lib/python3.8/asyncio/base_events.py", line 616, in run_until_complete
return future.result()
File "/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/src/python/grpcio_tests/tests_aio/unit/connectivity_test.py", line 54, in test_unavailable_backend
await asyncio.wait_for(
File "/Library/Frameworks/Python.framework/Versions/3.8/lib/python3.8/asyncio/tasks.py", line 501, in wait_for
raise exceptions.TimeoutError()
asyncio.exceptions.TimeoutError

stdout:
None
stderr:
None

Unexpected successes: []
/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/py38/lib/python3.8/site-packages/google/protobuf/runtime_version.py:112: UserWarning: Protobuf gencode version 5.27.2 is older than the runtime version 5.28.0 at grpc_channelz/v1/channelz.proto. Please avoid checked-in Protobuf gencode that can be obsolete.
warnings.warn(
/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/py38/lib/python3.8/site-packages/google/protobuf/runtime_version.py:112: UserWarning: Protobuf gencode version 5.27.2 is older than the runtime version 5.28.0 at grpc_health/v1/health.proto. Please avoid checked-in Protobuf gencode that can be obsolete.
warnings.warn(
/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/py38/lib/python3.8/site-packages/google/protobuf/runtime_version.py:112: UserWarning: Protobuf gencode version 5.27.2 is older than the runtime version 5.28.0 at src/proto/grpc/testing/empty.proto. Please avoid checked-in Protobuf gencode that can be obsolete.
warnings.warn(
/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/py38/lib/python3.8/site-packages/google/protobuf/runtime_version.py:112: UserWarning: Protobuf gencode version 5.27.2 is older than the runtime version 5.28.0 at src/proto/grpc/testing/messages.proto. Please avoid checked-in Protobuf gencode that can be obsolete.
warnings.warn(
/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/py38/lib/python3.8/site-packages/google/protobuf/runtime_version.py:112: UserWarning: Protobuf gencode version 5.27.2 is older than the runtime version 5.28.0 at grpc_reflection/v1alpha/reflection.proto. Please avoid checked-in Protobuf gencode that can be obsolete.
warnings.warn(
/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/py38/lib/python3.8/site-packages/google/protobuf/runtime_version.py:112: UserWarning: Protobuf gencode version 5.27.2 is older than the runtime version 5.28.0 at src/proto/grpc/testing/proto2/empty2_extensions.proto. Please avoid checked-in Protobuf gencode that can be obsolete.
warnings.warn(
/Volumes/BuildData/tmpfs/altsrc/github/grpc/workspace_python_macos_opt_native/py38/lib/python3.8/site-packages/google/protobuf/runtime_version.py:112: UserWarning: Protobuf gencode version 5.27.2 is older than the runtime version 5.28.0 at src/proto/grpc/testing/proto2/empty2.proto. Please avoid checked-in Protobuf gencode that can be obsolete.
warnings.warn(
Test failure
real 9.08
user 0.71
sys 0.14

2024-09-04 20:34:47,492 FAILED: py38.asyncio.tests_aio.unit.connectivity_test.TestConnectivityState [ret=1, pid=21687, time=9.1sec]
2024-09-04 20:34:47,492 START: py38.native.tests.testing._time_test.StrictFakeTimeTest
2024-09-04 20:34:47,766 PASSED: py38.native.tests.protoc_plugin._python_plugin_test.ModuleMainTest [time=1.2sec, retries=0:0; cpu_cost=1.1; estimated=1.0]
2024-09-04 20:34:47,766 START: py38.native.tests.unit._invalid_metadata_test.InvalidMetadataTest
2024-09-04 20:34:48,949 PASSED: py38.native.tests.unit._invalid_metadata_test.InvalidMetadataTest [time=1.2sec, retries=0:0; cpu_cost=0.9; estimated=1.0]
2024-09-04 20:34:48,950 START: py38.native.tests.unit._cython._server_test.Test
2024-09-04 20:34:51,383 PASSED: py38.native.tests.testing._time_test.StrictFakeTimeTest [time=3.9sec, retries=0:0; cpu_cost=0.9; estimated=1.0]
2024-09-04 20:34:51,390 START: py38.asyncio.tests_aio.unit.wait_for_ready_test.TestWaitForReady
2024-09-04 20:34:54,044 PASSED: py38.native.tests.unit._cython._server_test.Test [time=5.1sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:34:54,044 START: py38.native.tests.unit._exit_test.ExitTest
2024-09-04 20:34:55,259 PASSED: py38.native.tests.unit._exit_test.ExitTest [time=1.2sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:34:55,264 START: py38.native.tests.unit._error_message_encoding_test.ErrorMessageEncodingTest
2024-09-04 20:34:56,247 PASSED: py38.asyncio.tests_aio.unit.wait_for_ready_test.TestWaitForReady [time=4.9sec, retries=0:0; cpu_cost=0.2; estimated=1.0]
2024-09-04 20:34:56,248 START: py38.native.tests.observability._csm_observability_plugin_test.CSMObservabilityPluginTest
2024-09-04 20:34:56,334 PASSED: py38.native.tests.unit._error_message_encoding_test.ErrorMessageEncodingTest [time=1.1sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:34:56,351 START: py38.asyncio.tests_aio.channelz.channelz_servicer_test.ChannelzServicerTest
2024-09-04 20:34:56,492 PASSED: py38.native.tests.unit._cython._no_messages_single_server_completion_queue_test.Test [time=12.5sec, retries=0:0; cpu_cost=1.1; estimated=1.0]
2024-09-04 20:34:56,493 START: py38.native.tests.unit._server_shutdown_test.ServerShutdown
2024-09-04 20:34:57,237 PASSED: py38.native.tests.observability._csm_observability_plugin_test.CSMObservabilityPluginTest [time=1.0sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:34:57,237 START: py38.native.tests.unit._metadata_flags_test.MetadataFlagsTest
2024-09-04 20:34:59,079 PASSED: py38.native.tests.unit._server_shutdown_test.ServerShutdown [time=2.6sec, retries=0:0; cpu_cost=1.5; estimated=1.0]
2024-09-04 20:34:59,079 START: py38.native.tests.unit._empty_message_test.EmptyMessageTest
2024-09-04 20:34:59,861 PASSED: py38.native.tests.unit._metadata_flags_test.MetadataFlagsTest [time=2.6sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:34:59,863 START: py38.asyncio.tests_aio.unit.compatibility_test.TestCompatibility
2024-09-04 20:35:00,696 PASSED: py38.asyncio.tests_aio.channelz.channelz_servicer_test.ChannelzServicerTest [time=4.3sec, retries=0:0; cpu_cost=0.7; estimated=1.0]
2024-09-04 20:35:00,697 START: py38.native.tests.unit._logging_test.LoggingTest
2024-09-04 20:35:01,191 PASSED: py38.native.tests.unit._empty_message_test.EmptyMessageTest [time=2.1sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:01,192 START: py38.asyncio.tests_aio.unit.context_peer_test.TestContextPeer
2024-09-04 20:35:02,148 PASSED: py38.asyncio.tests_aio.unit.compatibility_test.TestCompatibility [time=2.3sec, retries=0:0; cpu_cost=0.9; estimated=1.0]
2024-09-04 20:35:02,149 START: py38.native.tests.unit._reconnect_test.ReconnectTest
2024-09-04 20:35:02,441 PASSED: py38.native.tests.unit._rpc_part_1_test.RPCPart1Test [time=17.9sec, retries=0:0; cpu_cost=0.9; estimated=1.0]
2024-09-04 20:35:02,442 START: py38.native.tests.unit._compression_test.CompressionTest
2024-09-04 20:35:02,854 PASSED: py38.native.tests.unit._logging_test.LoggingTest [time=2.2sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:02,855 START: py38.asyncio.tests_aio.health_check.health_servicer_test.HealthServicerTest
2024-09-04 20:35:02,910 PASSED: py38.asyncio.tests_aio.unit.context_peer_test.TestContextPeer [time=1.7sec, retries=0:0; cpu_cost=0.7; estimated=1.0]
2024-09-04 20:35:02,910 START: py38.native.tests.unit._server_wait_for_termination_test.ServerWaitForTerminationTest
2024-09-04 20:35:08,515 PASSED: py38.native.tests.unit._reconnect_test.ReconnectTest [time=6.4sec, retries=0:0; cpu_cost=0.9; estimated=1.0]
2024-09-04 20:35:08,516 START: py38.native.tests.protoc_plugin._split_definitions_test.SameProtoProtoBeforeGrpcProtocStyleTest
2024-09-04 20:35:09,034 PASSED: py38.native.tests.unit._compression_test.CompressionTest [time=6.6sec, retries=0:0; cpu_cost=1.2; estimated=1.0]
2024-09-04 20:35:09,037 START: py38.asyncio.tests_aio.unit.server_test.TestServer
2024-09-04 20:35:09,194 PASSED: py38.native.tests.unit._server_wait_for_termination_test.ServerWaitForTerminationTest [time=6.3sec, retries=0:0; cpu_cost=0.9; estimated=1.0]
2024-09-04 20:35:09,200 START: py38.asyncio.tests_aio.unit.done_callback_test.TestServerSideDoneCallback
2024-09-04 20:35:09,704 PASSED: py38.native.tests.protoc_plugin._split_definitions_test.SameProtoProtoBeforeGrpcProtocStyleTest [time=1.2sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:09,705 START: py38.native.tests.health_check._health_servicer_test.HealthServicerTest
2024-09-04 20:35:09,860 PASSED: py38.asyncio.tests_aio.health_check.health_servicer_test.HealthServicerTest [time=7.0sec, retries=0:0; cpu_cost=0.3; estimated=1.0]
2024-09-04 20:35:09,861 START: py38.asyncio.tests_aio.unit.secure_call_test.TestUnaryUnarySecureCall
2024-09-04 20:35:10,877 PASSED: py38.asyncio.tests_aio.unit.secure_call_test.TestUnaryUnarySecureCall [time=1.0sec, retries=0:0; cpu_cost=0.8; estimated=1.0]
2024-09-04 20:35:10,878 START: py38.native.tests.unit._server_test.ServerTest
2024-09-04 20:35:11,988 PASSED: py38.native.tests.unit._server_test.ServerTest [time=1.1sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:11,989 START: py38.native.tests._sanity._sanity_test.SanityTest
2024-09-04 20:35:13,428 PASSED: py38.native.tests._sanity._sanity_test.SanityTest [time=1.4sec, retries=0:0; cpu_cost=1.1; estimated=1.0]
2024-09-04 20:35:13,429 START: py38.asyncio.tests_aio.unit.close_channel_test.TestCloseChannel
2024-09-04 20:35:14,406 PASSED: py38.asyncio.tests_aio.unit.done_callback_test.TestServerSideDoneCallback [time=5.2sec, retries=0:0; cpu_cost=0.2; estimated=1.0]
2024-09-04 20:35:14,407 START: py38.native.tests.unit.beta._utilities_test.ChannelConnectivityTest
2024-09-04 20:35:14,748 PASSED: py38.asyncio.tests_aio.unit.close_channel_test.TestCloseChannel [time=1.3sec, retries=0:0; cpu_cost=0.7; estimated=1.0]
2024-09-04 20:35:14,748 START: py38.asyncio.tests_aio.unit.call_test.TestUnaryUnaryCall
2024-09-04 20:35:15,148 PASSED: py38.native.tests.health_check._health_servicer_test.HealthServicerTest [time=5.4sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:15,148 START: py38.native.tests.unit._auth_test.GoogleCallCredentialsTest
2024-09-04 20:35:15,655 PASSED: py38.native.tests.unit.beta._utilities_test.ChannelConnectivityTest [time=1.2sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:15,658 START: py38.asyncio.tests_aio.unit.channel_test.TestChannel
2024-09-04 20:35:16,566 PASSED: py38.asyncio.tests_aio.unit.call_test.TestUnaryUnaryCall [time=1.8sec, retries=0:0; cpu_cost=0.8; estimated=1.0]
2024-09-04 20:35:16,566 START: py38.native.tests.unit.beta._connectivity_channel_test.ConnectivityStatesTest
2024-09-04 20:35:16,673 PASSED: py38.native.tests.unit._auth_test.GoogleCallCredentialsTest [time=1.5sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:16,673 START: py38.native.tests.reflection._reflection_servicer_test.ReflectionServicerTest
2024-09-04 20:35:17,380 PASSED: py38.asyncio.tests_aio.unit.channel_test.TestChannel [time=1.7sec, retries=0:0; cpu_cost=0.7; estimated=1.0]
2024-09-04 20:35:17,380 START: py38.asyncio.tests_aio.unit.client_stream_unary_interceptor_test.TestStreamUnaryClientInterceptor
2024-09-04 20:35:17,646 PASSED: py38.native.tests.unit.beta._connectivity_channel_test.ConnectivityStatesTest [time=1.1sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:17,647 START: py38.native.tests.interop._insecure_intraop_test.InsecureIntraopTest
2024-09-04 20:35:17,933 PASSED: py38.native.tests.reflection._reflection_servicer_test.ReflectionServicerTest [time=1.3sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:17,934 START: py38.native.tests.observability._observability_plugin_test.ObservabilityPluginTest
2024-09-04 20:35:18,789 PASSED: py38.asyncio.tests_aio.unit.client_stream_unary_interceptor_test.TestStreamUnaryClientInterceptor [time=1.4sec, retries=0:0; cpu_cost=0.8; estimated=1.0]
2024-09-04 20:35:18,789 START: py38.asyncio.tests_aio.unit.wait_for_connection_test.TestWaitForConnection
2024-09-04 20:35:18,981 PASSED: py38.native.tests.observability._observability_plugin_test.ObservabilityPluginTest [time=1.0sec, retries=0:0; cpu_cost=0.9; estimated=1.0]
2024-09-04 20:35:18,981 START: py38.native.tests.unit._dynamic_stubs_test.DynamicStubTest
2024-09-04 20:35:19,111 PASSED: py38.native.tests.interop._insecure_intraop_test.InsecureIntraopTest [time=1.5sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:19,113 START: py38.asyncio.tests_aio.unit._metadata_test.TestTypeMetadata
2024-09-04 20:35:20,520 PASSED: py38.asyncio.tests_aio.unit._metadata_test.TestTypeMetadata [time=1.4sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:20,520 START: py38.asyncio.tests_aio.unit._metadata_test.TestMetadataWithServer
2024-09-04 20:35:20,656 PASSED: py38.native.tests.unit._dynamic_stubs_test.DynamicStubTest [time=1.7sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:20,663 START: py38.native.tests.observability._observability_api_test.AllTest
2024-09-04 20:35:20,703 PASSED: py38.asyncio.tests_aio.unit.server_test.TestServer [time=11.7sec, retries=0:0; cpu_cost=0.1; estimated=1.0]
2024-09-04 20:35:20,709 START: py38.asyncio.tests_aio.unit.call_test.TestUnaryStreamCall
2024-09-04 20:35:21,559 PASSED: py38.asyncio.tests_aio.unit._metadata_test.TestMetadataWithServer [time=1.0sec, retries=0:0; cpu_cost=0.8; estimated=1.0]
2024-09-04 20:35:21,560 START: py38.native.tests.channelz._channelz_servicer_test.ChannelzServicerTest
2024-09-04 20:35:21,657 PASSED: py38.native.tests.observability._observability_api_test.AllTest [time=1.0sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:21,658 START: py38.native.tests.unit._abort_test.AbortTest
2024-09-04 20:35:22,772 PASSED: py38.native.tests.unit._abort_test.AbortTest [time=1.1sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:22,772 START: py38.asyncio.tests_aio.status.grpc_status_test.StatusTest
2024-09-04 20:35:23,882 PASSED: py38.asyncio.tests_aio.status.grpc_status_test.StatusTest [time=1.1sec, retries=0:0; cpu_cost=0.8; estimated=1.0]
2024-09-04 20:35:23,883 START: py38.native.tests.csds.csds_test.TestCsdsStream
2024-09-04 20:35:23,910 PASSED: py38.native.tests.channelz._channelz_servicer_test.ChannelzServicerTest [time=2.3sec, retries=0:0; cpu_cost=1.2; estimated=1.0]
2024-09-04 20:35:23,917 START: py38.asyncio.tests_aio.unit.metadata_test.TestMetadata
2024-09-04 20:35:25,147 PASSED: py38.asyncio.tests_aio.unit.metadata_test.TestMetadata [time=1.2sec, retries=0:0; cpu_cost=0.8; estimated=1.0]
2024-09-04 20:35:25,148 START: py38.native.tests.unit._cython._channel_test.ChannelTest
2024-09-04 20:35:25,668 PASSED: py38.asyncio.tests_aio.unit.wait_for_connection_test.TestWaitForConnection [time=6.9sec, retries=0:0; cpu_cost=0.2; estimated=1.0]
2024-09-04 20:35:25,669 START: py38.native.tests.protoc_plugin._split_definitions_test.SplitProtoSingleProtocExecutionProtocStyleTest
2024-09-04 20:35:26,212 PASSED: py38.native.tests.csds.csds_test.TestCsdsStream [time=2.3sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:26,215 START: py38.native.tests.unit._invocation_defects_test.InvocationDefectsTest
2024-09-04 20:35:27,375 PASSED: py38.native.tests.protoc_plugin._split_definitions_test.SplitProtoSingleProtocExecutionProtocStyleTest [time=1.7sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:27,375 START: py38.native.tests.unit._server_ssl_cert_config_test.ServerSSLCertConfigFetcherParamsChecks
2024-09-04 20:35:27,955 PASSED: py38.native.tests.unit._invocation_defects_test.InvocationDefectsTest [time=1.7sec, retries=0:0; cpu_cost=1.1; estimated=1.0]
2024-09-04 20:35:27,955 START: py38.native.tests.protoc_plugin._split_definitions_test.SameProtoGrpcBeforeProtoProtocStyleTest
2024-09-04 20:35:28,470 PASSED: py38.native.tests.unit._server_ssl_cert_config_test.ServerSSLCertConfigFetcherParamsChecks [time=1.1sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:28,471 START: py38.native.tests.unit._api_test.ChannelConnectivityTest
2024-09-04 20:35:29,610 PASSED: py38.native.tests.protoc_plugin._split_definitions_test.SameProtoGrpcBeforeProtoProtocStyleTest [time=1.7sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:29,613 START: py38.native.tests.unit._cython.cygrpc_test.SecureServerSecureClient
2024-09-04 20:35:29,664 PASSED: py38.asyncio.tests_aio.unit.call_test.TestUnaryStreamCall [time=9.0sec, retries=0:0; cpu_cost=0.3; estimated=1.0]
2024-09-04 20:35:29,664 START: py38.native.tests.unit._api_test.AllTest
2024-09-04 20:35:30,112 PASSED: py38.native.tests.unit._api_test.ChannelConnectivityTest [time=1.6sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:30,113 START: py38.asyncio.tests_aio.unit.server_interceptor_test.TestServerInterceptor
2024-09-04 20:35:30,641 PASSED: py38.native.tests.unit._api_test.AllTest [time=1.0sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:30,647 START: py38.asyncio.tests_aio.unit.channel_argument_test.TestChannelArgument
2024-09-04 20:35:30,653 PASSED: py38.native.tests.unit._cython.cygrpc_test.SecureServerSecureClient [time=1.0sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:30,654 START: py38.native.tests.protoc_plugin._python_plugin_test.PythonPluginTest
2024-09-04 20:35:31,670 PASSED: py38.asyncio.tests_aio.unit.server_interceptor_test.TestServerInterceptor [time=1.6sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:31,671 START: py38.native.tests.unit._api_test.ChannelTest
2024-09-04 20:35:32,211 PASSED: py38.asyncio.tests_aio.unit.channel_argument_test.TestChannelArgument [time=1.6sec, retries=0:0; cpu_cost=0.9; estimated=1.0]
2024-09-04 20:35:32,212 START: py38.native.tests.testing._client_test.ClientTest
2024-09-04 20:35:32,890 PASSED: py38.native.tests.unit._api_test.ChannelTest [time=1.2sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:32,891 START: py38.native.tests.protoc_plugin._split_definitions_test.SameProtoMid2016ProtocStyleTest
2024-09-04 20:35:33,905 PASSED: py38.native.tests.testing._client_test.ClientTest [time=1.7sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:33,906 START: py38.native.tests.protoc_plugin.beta_python_plugin_test.PythonPluginTest
2024-09-04 20:35:34,182 PASSED: py38.native.tests.protoc_plugin._split_definitions_test.SameProtoMid2016ProtocStyleTest [time=1.3sec, retries=0:0; cpu_cost=0.9; estimated=1.0]
2024-09-04 20:35:34,182 START: py38.native.tests.protoc_plugin._split_definitions_test.SplitProtoGrpcBeforeProtoProtocStyleTest
2024-09-04 20:35:35,948 PASSED: py38.native.tests.protoc_plugin._split_definitions_test.SplitProtoGrpcBeforeProtoProtocStyleTest [time=1.8sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:35,949 START: py38.asyncio.tests_aio.interop.local_interop_test.InsecureLocalInteropTest
2024-09-04 20:35:38,354 PASSED: py38.asyncio.tests_aio.interop.local_interop_test.InsecureLocalInteropTest [time=2.4sec, retries=0:0; cpu_cost=0.5; estimated=1.0]
2024-09-04 20:35:38,355 START: py38.asyncio.tests_aio.unit.abort_test.TestAbort
2024-09-04 20:35:39,335 PASSED: py38.asyncio.tests_aio.unit.abort_test.TestAbort [time=1.0sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:39,335 START: py38.asyncio.tests_aio.unit.secure_call_test.TestStreamStreamSecureCall
2024-09-04 20:35:40,444 PASSED: py38.asyncio.tests_aio.unit.secure_call_test.TestStreamStreamSecureCall [time=1.1sec, retries=0:0; cpu_cost=0.8; estimated=1.0]
2024-09-04 20:35:40,445 START: py38.native.tests.csds.csds_test.TestCsds
2024-09-04 20:35:44,246 PASSED: py38.native.tests.csds.csds_test.TestCsds [time=3.8sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:44,246 START: py38.native.tests.protoc_plugin._split_definitions_test.SameProtoSingleProtocExecutionProtocStyleTest
2024-09-04 20:35:45,602 PASSED: py38.native.tests.protoc_plugin._split_definitions_test.SameProtoSingleProtocExecutionProtocStyleTest [time=1.4sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:45,604 START: py38.asyncio.tests_aio.interop.local_interop_test.SecureLocalInteropTest
2024-09-04 20:35:48,231 PASSED: py38.asyncio.tests_aio.interop.local_interop_test.SecureLocalInteropTest [time=2.6sec, retries=0:0; cpu_cost=0.5; estimated=1.0]
2024-09-04 20:35:48,231 START: py38.native.tests.unit.beta._not_found_test.NotFoundTest
2024-09-04 20:35:49,565 PASSED: py38.native.tests.unit.beta._not_found_test.NotFoundTest [time=1.3sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:49,578 START: py38.asyncio.tests_aio.unit.client_unary_unary_interceptor_test.TestInterceptedUnaryUnaryCall
2024-09-04 20:35:51,387 PASSED: py38.asyncio.tests_aio.unit.client_unary_unary_interceptor_test.TestInterceptedUnaryUnaryCall [time=1.8sec, retries=0:0; cpu_cost=0.7; estimated=1.0]
2024-09-04 20:35:51,388 START: py38.asyncio.tests_aio.unit.init_test.TestInit
2024-09-04 20:35:52,317 PASSED: py38.asyncio.tests_aio.unit.init_test.TestInit [time=0.9sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:52,317 START: py38.native.tests.unit._interceptor_test.InterceptorTest
2024-09-04 20:35:52,955 PASSED: py38.native.tests.protoc_plugin._python_plugin_test.PythonPluginTest [time=22.3sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:52,959 START: py38.native.tests.unit._server_test.ServerHandlerTest
2024-09-04 20:35:55,052 PASSED: py38.native.tests.unit._server_test.ServerHandlerTest [time=2.1sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:55,053 START: py38.native.tests.unit._cython.cygrpc_test.InsecureServerInsecureClient
2024-09-04 20:35:55,302 PASSED: py38.native.tests.unit._interceptor_test.InterceptorTest [time=3.0sec, retries=0:0; cpu_cost=1.1; estimated=1.0]
2024-09-04 20:35:55,303 START: py38.native.tests.protoc_plugin._python_plugin_test.SimpleStubsPluginTest
2024-09-04 20:35:55,859 PASSED: py38.native.tests.protoc_plugin.beta_python_plugin_test.PythonPluginTest [time=22.0sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:55,860 START: py38.native.tests.unit._local_credentials_test.LocalCredentialsTest
2024-09-04 20:35:56,233 PASSED: py38.native.tests.unit._cython.cygrpc_test.InsecureServerInsecureClient [time=1.2sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:56,233 START: py38.asyncio.tests_aio.unit.secure_call_test.TestUnaryStreamSecureCall
2024-09-04 20:35:56,622 PASSED: py38.native.tests.protoc_plugin._python_plugin_test.SimpleStubsPluginTest [time=1.3sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:56,623 START: py38.native.tests.unit.framework.foundation._logging_pool_test.LoggingPoolTest
2024-09-04 20:35:57,683 PASSED: py38.native.tests.unit._local_credentials_test.LocalCredentialsTest [time=1.8sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:57,684 START: py38.native.tests.unit._server_ssl_cert_config_test.ServerSSLCertReloadTestWithoutClientAuth
2024-09-04 20:35:57,828 PASSED: py38.asyncio.tests_aio.unit.secure_call_test.TestUnaryStreamSecureCall [time=1.6sec, retries=0:0; cpu_cost=0.9; estimated=1.0]
2024-09-04 20:35:57,829 START: py38.native.tests.observability._open_telemetry_observability_test.OpenTelemetryObservabilityTest
2024-09-04 20:35:58,427 PASSED: py38.native.tests.unit.framework.foundation._logging_pool_test.LoggingPoolTest [time=1.8sec, retries=0:0; cpu_cost=0.9; estimated=1.0]
2024-09-04 20:35:58,427 START: py38.asyncio.tests_aio.unit.done_callback_test.TestClientSideDoneCallback
2024-09-04 20:35:58,931 PASSED: py38.native.tests.observability._open_telemetry_observability_test.OpenTelemetryObservabilityTest [time=1.1sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:35:58,932 START: py38.native.tests.protoc_plugin._split_definitions_test.SplitProtoMid2016ProtocStyleTest
2024-09-04 20:35:59,635 PASSED: py38.asyncio.tests_aio.unit.done_callback_test.TestClientSideDoneCallback [time=1.2sec, retries=0:0; cpu_cost=0.8; estimated=1.0]
2024-09-04 20:35:59,636 START: py38.native.tests.unit._cython._read_some_but_not_all_responses_test.ReadSomeButNotAllResponsesTest
2024-09-04 20:36:00,282 PASSED: py38.native.tests.protoc_plugin._split_definitions_test.SplitProtoMid2016ProtocStyleTest [time=1.3sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:36:00,284 START: py38.native.tests.unit._grpc_shutdown_test.GrpcShutdownTest
2024-09-04 20:36:00,505 PASSED: py38.native.tests.unit._server_ssl_cert_config_test.ServerSSLCertReloadTestWithoutClientAuth [time=2.8sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:36:00,507 START: py38.native.tests.unit._metadata_test.MetadataTest
2024-09-04 20:36:01,347 PASSED: py38.native.tests.unit._cython._read_some_but_not_all_responses_test.ReadSomeButNotAllResponsesTest [time=1.7sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:36:01,348 START: py38.asyncio.tests_aio.unit.auth_context_test.TestAuthContext
2024-09-04 20:36:02,122 PASSED: py38.native.tests.unit._metadata_test.MetadataTest [time=1.6sec, retries=0:0; cpu_cost=1.1; estimated=1.0]
2024-09-04 20:36:02,122 START: py38.native.tests.health_check._health_servicer_test.HealthServicerBackwardsCompatibleWatchTest
2024-09-04 20:36:02,590 PASSED: py38.asyncio.tests_aio.unit.auth_context_test.TestAuthContext [time=1.2sec, retries=0:0; cpu_cost=0.8; estimated=1.0]
2024-09-04 20:36:02,591 START: py38.asyncio.tests_aio.unit.server_time_remaining_test.TestServerTimeRemaining
2024-09-04 20:36:03,677 PASSED: py38.asyncio.tests_aio.unit.server_time_remaining_test.TestServerTimeRemaining [time=1.1sec, retries=0:0; cpu_cost=0.8; estimated=1.0]
2024-09-04 20:36:03,677 START: py38.native.tests.unit.beta._beta_features_test.ContextManagementAndLifecycleTest
2024-09-04 20:36:07,290 PASSED: py38.native.tests.health_check._health_servicer_test.HealthServicerBackwardsCompatibleWatchTest [time=5.2sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:36:07,291 START: py38.native.tests.unit._cython._fork_test.ForkPosixTester
2024-09-04 20:36:07,451 PASSED: py38.native.tests.unit._cython._channel_test.ChannelTest [time=42.3sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:36:07,452 START: py38.native.tests.status._grpc_status_test.StatusTest
2024-09-04 20:36:08,371 PASSED: py38.native.tests.unit._cython._fork_test.ForkPosixTester [time=1.1sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:36:08,372 START: py38.native.tests.unit._metadata_code_details_test.MetadataCodeDetailsTest
2024-09-04 20:36:08,673 PASSED: py38.native.tests.status._grpc_status_test.StatusTest [time=1.2sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:36:08,673 START: py38.asyncio.tests_aio.unit.channel_ready_test.TestChannelReady
2024-09-04 20:36:11,865 PASSED: py38.native.tests.unit._grpc_shutdown_test.GrpcShutdownTest [time=11.6sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:36:11,866 START: py38.native.tests.unit._session_cache_test.SSLSessionCacheTest
2024-09-04 20:36:12,403 PASSED: py38.native.tests.unit.beta._beta_features_test.ContextManagementAndLifecycleTest [time=8.7sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:36:12,404 START: py38.native.tests.testing._server_test.FirstServiceServicerTest
2024-09-04 20:36:12,934 PASSED: py38.native.tests.unit._metadata_code_details_test.MetadataCodeDetailsTest [time=4.6sec, retries=0:0; cpu_cost=1.2; estimated=1.0]
2024-09-04 20:36:12,939 START: py38.native.tests.observability._csm_observability_plugin_test.MetadataExchangeTest
2024-09-04 20:36:13,149 PASSED: py38.native.tests.unit._session_cache_test.SSLSessionCacheTest [time=1.3sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:36:13,149 START: py38.native.tests.protoc_plugin._split_definitions_test.WellKnownTypesTest
2024-09-04 20:36:14,474 PASSED: py38.asyncio.tests_aio.unit.channel_ready_test.TestChannelReady [time=5.8sec, retries=0:0; cpu_cost=0.2; estimated=1.0]
2024-09-04 20:36:14,475 START: py38.native.tests.unit._auth_test.AccessTokenAuthMetadataPluginTest
2024-09-04 20:36:14,490 PASSED: py38.native.tests.observability._csm_observability_plugin_test.MetadataExchangeTest [time=1.5sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:36:14,490 START: py38.asyncio.tests_aio.unit.call_test.TestStreamUnaryCall
2024-09-04 20:36:14,692 PASSED: py38.native.tests.protoc_plugin._split_definitions_test.WellKnownTypesTest [time=1.5sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:36:14,693 START: py38.native.tests.unit._rpc_part_2_test.RPCPart2Test
2024-09-04 20:36:14,771 PASSED: py38.native.tests.testing._server_test.FirstServiceServicerTest [time=2.4sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:36:14,772 START: py38.native.tests.unit._cython._no_messages_server_completion_queue_per_call_test.Test
2024-09-04 20:36:16,209 PASSED: py38.native.tests.unit._auth_test.AccessTokenAuthMetadataPluginTest [time=1.7sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:36:16,210 START: py38.asyncio.tests_aio.unit.aio_rpc_error_test.TestAioRpcError
2024-09-04 20:36:17,960 PASSED: py38.asyncio.tests_aio.unit.aio_rpc_error_test.TestAioRpcError [time=1.7sec, retries=0:0; cpu_cost=0.7; estimated=1.0]
2024-09-04 20:36:17,961 START: py38.asyncio.tests_aio.reflection.reflection_servicer_test.ReflectionServicerTest
2024-09-04 20:36:19,459 PASSED: py38.asyncio.tests_aio.unit.call_test.TestStreamUnaryCall [time=5.0sec, retries=0:0; cpu_cost=0.3; estimated=1.0]
2024-09-04 20:36:19,460 START: py38.native.tests.reflection._reflection_client_test.ReflectionClientTest
2024-09-04 20:36:20,125 PASSED: py38.asyncio.tests_aio.reflection.reflection_servicer_test.ReflectionServicerTest [time=2.2sec, retries=0:0; cpu_cost=0.7; estimated=1.0]
2024-09-04 20:36:20,125 START: py38.asyncio.tests_aio._sanity._sanity_test.AioSanityTest
2024-09-04 20:36:22,023 PASSED: py38.native.tests.reflection._reflection_client_test.ReflectionClientTest [time=2.6sec, retries=0:0; cpu_cost=0.8; estimated=1.0]
2024-09-04 20:36:22,024 START: py38.native.tests.unit._signal_handling_test.SignalHandlingTest
2024-09-04 20:36:22,209 PASSED: py38.asyncio.tests_aio._sanity._sanity_test.AioSanityTest [time=2.1sec, retries=0:0; cpu_cost=0.7; estimated=1.0]
2024-09-04 20:36:22,210 START: py38.native.tests.unit._metadata_code_details_test.InspectContextTest
2024-09-04 20:36:23,622 PASSED: py38.native.tests.unit._metadata_code_details_test.InspectContextTest [time=1.4sec, retries=0:0; cpu_cost=0.9; estimated=1.0]
2024-09-04 20:36:23,623 START: py38.native.tests.unit._resource_exhausted_test.ResourceExhaustedTest
2024-09-04 20:36:25,019 PASSED: py38.native.tests.unit._signal_handling_test.SignalHandlingTest [time=3.0sec, retries=0:0; cpu_cost=1.1; estimated=1.0]
2024-09-04 20:36:25,019 START: py38.native.tests.testing._time_test.StrictRealTimeTest
2024-09-04 20:36:28,095 PASSED: py38.native.tests.unit._resource_exhausted_test.ResourceExhaustedTest [time=4.5sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:36:28,096 START: py38.asyncio.tests_aio.unit.outside_init_test.TestOutsideInit
2024-09-04 20:36:29,552 PASSED: py38.native.tests.unit._cython._no_messages_server_completion_queue_per_call_test.Test [time=14.8sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:36:29,552 START: py38.asyncio.tests_aio.unit.timeout_test.TestTimeout
2024-09-04 20:36:29,941 PASSED: py38.asyncio.tests_aio.unit.outside_init_test.TestOutsideInit [time=1.8sec, retries=0:0; cpu_cost=0.8; estimated=1.0]
2024-09-04 20:36:29,943 START: py38.native.tests.unit._cython._fork_test.ForkWindowsTester
2024-09-04 20:36:31,838 PASSED: py38.native.tests.unit._cython._fork_test.ForkWindowsTester [time=1.9sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:36:31,839 START: py38.native.tests.unit._channel_close_test.ChannelCloseTest
2024-09-04 20:36:37,367 PASSED: py38.native.tests.testing._time_test.StrictRealTimeTest [time=12.3sec, retries=0:0; cpu_cost=0.9; estimated=1.0]
2024-09-04 20:36:37,367 START: py38.native.tests.fork._fork_interop_test.ForkInteropTest
2024-09-04 20:36:37,867 PASSED: py38.asyncio.tests_aio.unit.timeout_test.TestTimeout [time=8.3sec, retries=0:0; cpu_cost=0.2; estimated=1.0]
2024-09-04 20:36:37,868 START: py38.native.tests.unit._contextvars_propagation_test.ContextVarsPropagationTest
2024-09-04 20:36:39,400 PASSED: py38.native.tests.fork._fork_interop_test.ForkInteropTest [time=2.0sec, retries=0:0; cpu_cost=0.9; estimated=1.0]
2024-09-04 20:36:39,494 PASSED: py38.native.tests.unit._rpc_part_2_test.RPCPart2Test [time=24.8sec, retries=0:0; cpu_cost=1.1; estimated=1.0]
2024-09-04 20:36:41,338 PASSED: py38.native.tests.unit._contextvars_propagation_test.ContextVarsPropagationTest [time=3.5sec, retries=0:0; cpu_cost=1.2; estimated=1.0]
2024-09-04 20:36:43,694 PASSED: py38.native.tests.unit._channel_close_test.ChannelCloseTest [time=11.9sec, retries=0:0; cpu_cost=1.0; estimated=1.0]
2024-09-04 20:36:43,694 FAILED: py38.asyncio.tests_aio.unit.connectivity_test.TestConnectivityState
2024-09-04 20:36:43,710 Attempting refresh to obtain initial access_token
2024-09-04 20:36:43,717 Refreshing access_token
2024-09-04 20:36:44,617 FAILED: Some tests failed
Warning: Table aggregate_results already exists

=== run_tests.py DEBUG INFO ===
command: "workspace_python_macos_opt_native/tools/run_tests/run_tests.py -t -j 4 -x run_tests/python_macos_opt_native/sponge_log.xml --report_suite_name python_macos_opt_native -l python -c opt --iomgr_platform native --bq_result_table aggregate_results --measure_cpu_costs --report_multi_target"
kokoro job name: grpc/core/master/macos/grpc_basictests_python
===============================

2024-09-04 20:36:44,671 FAILED: run_tests_python_macos_opt_native [ret=2, pid=15286, time=910.7sec]
2024-09-04 20:36:44,681 FAILED: Some run_tests.py instances have failed.
+ FAILED=true
+ ps aux
+ grep 'port_server\.py'
+ awk '{print $2}'
+ xargs kill -9
+ '[' true '!=' '' ']'
+ exit 1


[ID: 4089877] Command finished after 1102 secs, exit value: 1


Warning: Permanently added 'localhost' (ED25519) to the list of known hosts.
[20:36:45 PDT] Collecting build artifacts from build VM
Build script failed with exit code: 1