This job view page is being replaced by Spyglass soon. Check out the new job view.
PRJonher937: [cinder-csi-plugin] Add option to ignore blockstorage microversion on older clouds
Resultsuccess
Tests 0 failed / 0 succeeded
Started2022-09-06 00:20
Elapsed1h46m
Revision
Refs 1986
uploadercrier
uploadercrier

No Test Failures!


Error lines from build-log.txt

... skipping 303 lines ...
PLAY [all] *********************************************************************

TASK [Gathering Facts] *********************************************************
ok: [34.150.148.63]

TASK [install-golang : Check if go has satisfied requirement] ******************
fatal: [34.150.148.63]: FAILED! => {
    "changed": true,
    "cmd": "/usr/local/go/bin/go version |grep -Eo '([0-9]+\\.)+[0-9]+'",
    "delta": "0:00:00.003566",
    "end": "2022-09-06 00:25:13.784160",
    "rc": 1,
    "start": "2022-09-06 00:25:13.780594"
... skipping 2576 lines ...
Enabling module setenvif.
Enabling module filter.
Enabling module deflate.
Enabling module status.
Enabling module reqtimeout.
Enabling conf charset.
Enabling conf localized-error-pages.

Enabling conf other-vhosts-access-log.
Enabling conf security.
Enabling conf serve-cgi-bin.
Enabling site 000-default.
info: Executing deferred 'a2enconf javascript-common' for package javascript-common
Enabling conf javascript-common.
... skipping 145 lines ...
Using python 3.8 to install setuptools!=24.0.0,!=34.0.0,!=34.0.1,!=34.0.2,!=34.0.3,!=34.1.0,!=34.1.1,!=34.2.0,!=34.3.0,!=34.3.1,!=34.3.2,!=36.2.0,!=48.0.0,!=49.0.0
+ inc/python:pip_install:193               :   sudo -H LC_ALL=en_US.UTF-8 SETUPTOOLS_USE_DISTUTILS=stdlib http_proxy= https_proxy= no_proxy= PIP_FIND_LINKS= SETUPTOOLS_SYS_PATH_TECHNIQUE=rewrite python3.8 -m pip install -c /opt/stack/requirements/upper-constraints.txt --ignore-installed 'setuptools!=24.0.0,!=34.0.0,!=34.0.1,!=34.0.2,!=34.0.3,!=34.1.0,!=34.1.1,!=34.2.0,!=34.3.0,!=34.3.1,!=34.3.2,!=36.2.0,!=48.0.0,!=49.0.0'
Collecting setuptools!=24.0.0,!=34.0.0,!=34.0.1,!=34.0.2,!=34.0.3,!=34.1.0,!=34.1.1,!=34.2.0,!=34.3.0,!=34.3.1,!=34.3.2,!=36.2.0,!=48.0.0,!=49.0.0
  Downloading setuptools-57.4.0-py3-none-any.whl (819 kB)
     ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 819.0/819.0 kB 53.8 MB/s eta 0:00:00
Installing collected packages: setuptools
ERROR: pip's dependency resolver does not currently take into account all the packages that are installed. This behaviour is the source of the following dependency conflicts.
launchpadlib 1.10.13 requires testresources, which is not installed.
Successfully installed setuptools-57.4.0
WARNING: Running pip as the 'root' user can result in broken permissions and conflicting behaviour with the system package manager. It is recommended to use a virtual environment instead: https://pip.pypa.io/warnings/venv
+ inc/python:pip_install:200               :   result=0
+ inc/python:pip_install:202               :   time_stop pip_install
+ functions-common:time_stop:2342          :   local name
... skipping 137 lines ...
  Building wheel for pyperclip (setup.py): started
  Building wheel for pyperclip (setup.py): finished with status 'done'
  Created wheel for pyperclip: filename=pyperclip-1.8.2-py3-none-any.whl size=11136 sha256=01e6c259b1c7134d760b51c9b3eb5f4d8ff428ee13dc3700cb35473d6a72585e
  Stored in directory: /root/.cache/pip/wheels/7f/1a/65/84ff8c386bec21fca6d220ea1f5498a0367883a78dd5ba6122
Successfully built future PrettyTable pyperclip
Installing collected packages: wcwidth, voluptuous, pyperclip, PrettyTable, extras, six, PyYAML, pyparsing, pbr, future, colorama, autopage, attrs, stevedore, cmd2, cliff, fixtures, testtools, python-subunit, stestr, os-testr
ERROR: pip's dependency resolver does not currently take into account all the packages that are installed. This behaviour is the source of the following dependency conflicts.
launchpadlib 1.10.13 requires testresources, which is not installed.
Successfully installed PrettyTable-0.7.2 PyYAML-5.4.1 attrs-21.2.0 autopage-0.4.0 cliff-3.9.0 cmd2-2.1.2 colorama-0.4.4 extras-1.0.0 fixtures-3.0.0 future-0.18.2 os-testr-2.0.1 pbr-5.6.0 pyparsing-2.4.7 pyperclip-1.8.2 python-subunit-1.4.0 six-1.16.0 stestr-3.2.0 stevedore-3.4.1 testtools-2.5.0 voluptuous-0.12.1 wcwidth-0.2.5
WARNING: Running pip as the 'root' user can result in broken permissions and conflicting behaviour with the system package manager. It is recommended to use a virtual environment instead: https://pip.pypa.io/warnings/venv
+ inc/python:pip_install:200               :   result=0
+ inc/python:pip_install:202               :   time_stop pip_install
+ functions-common:time_stop:2342          :   local name
... skipping 110 lines ...
Collecting colorama===0.4.4
  Downloading colorama-0.4.4-py2.py3-none-any.whl (16 kB)
Collecting wcwidth===0.2.5
  Downloading wcwidth-0.2.5-py2.py3-none-any.whl (30 kB)
Building wheels for collected packages: prettytable, pyperclip, openstack-requirements
  Building wheel for prettytable (setup.py): started
  Building wheel for prettytable (setup.py): finished with status 'error'
  ERROR: Command errored out with exit status 1:
   command: /opt/stack/requirements/.venv/bin/python3 -u -c 'import sys, setuptools, tokenize; sys.argv[0] = '"'"'/tmp/pip-install-hk7rh8hz/prettytable/setup.py'"'"'; __file__='"'"'/tmp/pip-install-hk7rh8hz/prettytable/setup.py'"'"';f=getattr(tokenize, '"'"'open'"'"', open)(__file__);code=f.read().replace('"'"'\r\n'"'"', '"'"'\n'"'"');f.close();exec(compile(code, __file__, '"'"'exec'"'"'))' bdist_wheel -d /tmp/pip-wheel-1fwtfrcq
       cwd: /tmp/pip-install-hk7rh8hz/prettytable/
  Complete output (6 lines):
  usage: setup.py [global_opts] cmd1 [cmd1_opts] [cmd2 [cmd2_opts] ...]
     or: setup.py --help [cmd1 cmd2 ...]
     or: setup.py --help-commands
     or: setup.py cmd --help
  
  error: invalid command 'bdist_wheel'
  ----------------------------------------
  ERROR: Failed building wheel for prettytable
  Running setup.py clean for prettytable
  Building wheel for pyperclip (setup.py): started
  Building wheel for pyperclip (setup.py): finished with status 'error'
  ERROR: Command errored out with exit status 1:
   command: /opt/stack/requirements/.venv/bin/python3 -u -c 'import sys, setuptools, tokenize; sys.argv[0] = '"'"'/tmp/pip-install-hk7rh8hz/pyperclip/setup.py'"'"'; __file__='"'"'/tmp/pip-install-hk7rh8hz/pyperclip/setup.py'"'"';f=getattr(tokenize, '"'"'open'"'"', open)(__file__);code=f.read().replace('"'"'\r\n'"'"', '"'"'\n'"'"');f.close();exec(compile(code, __file__, '"'"'exec'"'"'))' bdist_wheel -d /tmp/pip-wheel-vw2k7hob
       cwd: /tmp/pip-install-hk7rh8hz/pyperclip/
  Complete output (6 lines):
  usage: setup.py [global_opts] cmd1 [cmd1_opts] [cmd2 [cmd2_opts] ...]
     or: setup.py --help [cmd1 cmd2 ...]
     or: setup.py --help-commands
     or: setup.py cmd --help
  
  error: invalid command 'bdist_wheel'
  ----------------------------------------
  ERROR: Failed building wheel for pyperclip
  Running setup.py clean for pyperclip
  Building wheel for openstack-requirements (setup.py): started
  Building wheel for openstack-requirements (setup.py): finished with status 'error'
  ERROR: Command errored out with exit status 1:
   command: /opt/stack/requirements/.venv/bin/python3 -u -c 'import sys, setuptools, tokenize; sys.argv[0] = '"'"'/tmp/pip-req-build-3ji0x93j/setup.py'"'"'; __file__='"'"'/tmp/pip-req-build-3ji0x93j/setup.py'"'"';f=getattr(tokenize, '"'"'open'"'"', open)(__file__);code=f.read().replace('"'"'\r\n'"'"', '"'"'\n'"'"');f.close();exec(compile(code, __file__, '"'"'exec'"'"'))' bdist_wheel -d /tmp/pip-wheel-j2_2adji
       cwd: /tmp/pip-req-build-3ji0x93j/
  Complete output (6 lines):
  usage: setup.py [global_opts] cmd1 [cmd1_opts] [cmd2 [cmd2_opts] ...]
     or: setup.py --help [cmd1 cmd2 ...]
     or: setup.py --help-commands
     or: setup.py cmd --help
  
  error: invalid command 'bdist_wheel'
  ----------------------------------------
  ERROR: Failed building wheel for openstack-requirements
  Running setup.py clean for openstack-requirements
Failed to build prettytable pyperclip openstack-requirements
Installing collected packages: certifi, pbr, attrs, extras, testtools, six, fixtures, wcwidth, prettytable, urllib3, PyYAML, idna, charset-normalizer, requests, stevedore, pyparsing, pyperclip, colorama, cmd2, autopage, cliff, packaging, Parsley, beagle, openstack-requirements
    Running setup.py install for prettytable: started
    Running setup.py install for prettytable: finished with status 'done'
    Running setup.py install for pyperclip: started
    Running setup.py install for pyperclip: finished with status 'done'
    Running setup.py install for openstack-requirements: started
... skipping 642 lines ...
update-alternatives: using /var/lib/mecab/dic/ipadic-utf8 to provide /var/lib/mecab/dic/debian (mecab-dictionary) in auto mode
Setting up libhtml-parser-perl (3.72-5) ...
Setting up libhttp-message-perl (6.22-1) ...
Setting up mysql-server-8.0 (8.0.30-0ubuntu0.20.04.2) ...
update-alternatives: using /etc/mysql/mysql.cnf to provide /etc/mysql/my.cnf (my.cnf) in auto mode
Renaming removed key_buffer and myisam-recover options (if present)
mysqld will log errors to /var/log/mysql/error.log

mysqld is running as pid 28919
Created symlink /etc/systemd/system/multi-user.target.wants/mysql.service → /lib/systemd/system/mysql.service.
Setting up libcgi-pm-perl (4.46-1) ...
Setting up libhtml-template-perl (2.97-1) ...
Setting up mysql-server (8.0.30-0ubuntu0.20.04.2) ...
Setting up libcgi-fast-perl (1:2.15-1) ...
... skipping 110 lines ...
Fetched 59.0 kB in 0s (960 kB/s)
Selecting previously unselected package radvd.
(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 ... 91551 files and directories currently installed.)
Preparing to unpack .../radvd_1%3a2.17-2_amd64.deb ...
Unpacking radvd (1:2.17-2) ...
Setting up radvd (1:2.17-2) ...
Job for radvd.service failed because the control process exited with error code.

See "systemctl status radvd.service" and "journalctl -xe" for details.
invoke-rc.d: initscript radvd, action "start" failed.

● radvd.service - Router advertisement daemon for IPv6
     Loaded: loaded (]8;;file://devstack/lib/systemd/system/radvd.service/lib/systemd/system/radvd.service]8;;; disabled; vendor preset: enabled)
     Active: failed (Result: exit-code) since Tue 2022-09-06 00:29:04 UTC; 8ms ago

       Docs: ]8;;man:radvd(8)man:radvd(8)]8;;
    Process: 30066 ExecStartPre=/usr/sbin/radvd --logmethod stderr_clean --configtest (code=exited, status=1/FAILURE)

Sep 06 00:29:04 devstack systemd[1]: Starting Router advertisement daemon for IPv6...
Sep 06 00:29:04 devstack radvd[30066]: can't open /etc/radvd.conf: No such file or directory
Sep 06 00:29:04 devstack radvd[30066]: Insecure file permissions, but continuing anyway
Sep 06 00:29:04 devstack radvd[30066]: exiting, failed to read config file

Sep 06 00:29:04 devstack systemd[1]: radvd.service: Control process exited, code=exited, status=1/FAILURE
Sep 06 00:29:04 devstack systemd[1]: radvd.service: Failed with result 'exit-code'.

Sep 06 00:29:04 devstack systemd[1]: Failed to start Router advertisement daemon for IPv6.

Processing triggers for man-db (2.9.1-1) ...
Processing triggers for systemd (245.4-4ubuntu3.17) ...
+ functions-common:apt_get:1137            :   result=0
+ functions-common:apt_get:1140            :   time_stop apt-get
+ functions-common:time_stop:2342          :   local name
+ functions-common:time_stop:2343          :   local end_time
... skipping 468 lines ...
  Building wheel for etcd3 (setup.py): started
  Building wheel for etcd3 (setup.py): finished with status 'done'
  Created wheel for etcd3: filename=etcd3-0.12.0-py2.py3-none-any.whl size=42886 sha256=0b83d611bedbfd13409c30600a13d5c845dbb3255c74032972990400040e093e
  Stored in directory: /root/.cache/pip/wheels/01/af/36/31f9f42a3b49c1998e9bdaec85a28e4c9a24c0d8a4f81293d7
Successfully built etcd3
Installing collected packages: six, tenacity, protobuf, grpcio, etcd3
ERROR: pip's dependency resolver does not currently take into account all the packages that are installed. This behaviour is the source of the following dependency conflicts.
launchpadlib 1.10.13 requires testresources, which is not installed.
Successfully installed etcd3-0.12.0 grpcio-1.39.0 protobuf-3.17.3 six-1.16.0 tenacity-6.3.1
WARNING: Running pip as the 'root' user can result in broken permissions and conflicting behaviour with the system package manager. It is recommended to use a virtual environment instead: https://pip.pypa.io/warnings/venv
+ inc/python:pip_install:200               :   result=0
+ inc/python:pip_install:202               :   time_stop pip_install
+ functions-common:time_stop:2342          :   local name
... skipping 34 lines ...
  Downloading urllib3-1.26.6-py2.py3-none-any.whl (138 kB)
     ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 138.5/138.5 kB 30.6 MB/s eta 0:00:00
Collecting certifi>=2017.4.17
  Downloading certifi-2021.5.30-py2.py3-none-any.whl (145 kB)
     ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 145.5/145.5 kB 32.3 MB/s eta 0:00:00
Installing collected packages: certifi, urllib3, six, pbr, idna, charset-normalizer, requests, futurist, etcd3gw
ERROR: pip's dependency resolver does not currently take into account all the packages that are installed. This behaviour is the source of the following dependency conflicts.
launchpadlib 1.10.13 requires testresources, which is not installed.
Successfully installed certifi-2021.5.30 charset-normalizer-2.0.4 etcd3gw-1.0.0 futurist-2.4.0 idna-3.2 pbr-5.6.0 requests-2.26.0 six-1.16.0 urllib3-1.26.6
WARNING: Running pip as the 'root' user can result in broken permissions and conflicting behaviour with the system package manager. It is recommended to use a virtual environment instead: https://pip.pypa.io/warnings/venv
+ inc/python:pip_install:200               :   result=0
+ inc/python:pip_install:202               :   time_stop pip_install
+ functions-common:time_stop:2342          :   local name
... skipping 315 lines ...
  Building wheel for wrapt (setup.py): started
  Building wheel for wrapt (setup.py): finished with status 'done'
  Created wheel for wrapt: filename=wrapt-1.12.1-cp38-cp38-linux_x86_64.whl size=78569 sha256=86412a2d7e36bd8146314a463756799fcb91ec4afbd97371e6c7b4694dfe5460
  Stored in directory: /root/.cache/pip/wheels/5f/fd/9e/b6cf5890494cb8ef0b5eaff72e5d55a70fb56316007d6dfe73
Successfully built pyinotify wrapt
Installing collected packages: wrapt, rfc3986, pytz, pyinotify, netifaces, netaddr, msgpack, iso8601, certifi, WebOb, urllib3, six, PyYAML, pyparsing, pbr, idna, decorator, charset-normalizer, stevedore, requests, python-dateutil, packaging, oslo.i18n, os-service-types, debtcollector, oslo.utils, oslo.context, oslo.config, keystoneauth1, dogpile.cache, oslo.serialization, python-keystoneclient, pycadf, oslo.log, oslo.cache, keystonemiddleware
ERROR: pip's dependency resolver does not currently take into account all the packages that are installed. This behaviour is the source of the following dependency conflicts.
launchpadlib 1.10.13 requires testresources, which is not installed.
Successfully installed PyYAML-5.4.1 WebOb-1.8.7 certifi-2021.5.30 charset-normalizer-2.0.4 debtcollector-2.3.0 decorator-5.0.9 dogpile.cache-1.1.5 idna-3.2 iso8601-0.1.16 keystoneauth1-4.4.0 keystonemiddleware-9.3.0 msgpack-1.0.2 netaddr-0.8.0 netifaces-0.11.0 os-service-types-1.7.0 oslo.cache-2.8.2 oslo.config-8.7.1 oslo.context-3.3.2 oslo.i18n-5.1.0 oslo.log-4.6.0 oslo.serialization-4.2.0 oslo.utils-4.10.2 packaging-21.0 pbr-5.6.0 pycadf-3.1.1 pyinotify-0.9.6 pyparsing-2.4.7 python-dateutil-2.8.2 python-keystoneclient-4.3.0 pytz-2021.1 requests-2.26.0 rfc3986-1.5.0 six-1.16.0 stevedore-3.4.1 urllib3-1.26.6 wrapt-1.12.1
WARNING: Running pip as the 'root' user can result in broken permissions and conflicting behaviour with the system package manager. It is recommended to use a virtual environment instead: https://pip.pypa.io/warnings/venv
+ inc/python:pip_install:200               :   result=0
+ inc/python:pip_install:202               :   time_stop pip_install
+ functions-common:time_stop:2342          :   local name
... skipping 28 lines ...
+ inc/python:pip_install:193               :   sudo -H LC_ALL=en_US.UTF-8 SETUPTOOLS_USE_DISTUTILS=stdlib http_proxy= https_proxy= no_proxy= PIP_FIND_LINKS= SETUPTOOLS_SYS_PATH_TECHNIQUE=rewrite python3.8 -m pip install -c /opt/stack/requirements/upper-constraints.txt --ignore-installed python-memcached
Collecting python-memcached
  Downloading python_memcached-1.59-py2.py3-none-any.whl (16 kB)
Collecting six>=1.4.0
  Using cached six-1.16.0-py2.py3-none-any.whl (11 kB)
Installing collected packages: six, python-memcached
ERROR: pip's dependency resolver does not currently take into account all the packages that are installed. This behaviour is the source of the following dependency conflicts.
launchpadlib 1.10.13 requires testresources, which is not installed.
Successfully installed python-memcached-1.59 six-1.16.0
WARNING: Running pip as the 'root' user can result in broken permissions and conflicting behaviour with the system package manager. It is recommended to use a virtual environment instead: https://pip.pypa.io/warnings/venv
+ inc/python:pip_install:200               :   result=0
+ inc/python:pip_install:202               :   time_stop pip_install
+ functions-common:time_stop:2342          :   local name
... skipping 445 lines ...
+ functions:setup_systemd_logging:695      :   local pidstr=
+ functions:setup_systemd_logging:696      :   [[ False == \T\r\u\e ]]
+ functions:setup_systemd_logging:700      :   pidstr='(pid=%(process)d) '
+ functions:setup_systemd_logging:702      :   iniset /etc/keystone/keystone.conf DEFAULT logging_debug_format_suffix '{{(pid=%(process)d) %(funcName)s %(pathname)s:%(lineno)d}}'
+ functions:setup_systemd_logging:704      :   iniset /etc/keystone/keystone.conf DEFAULT logging_context_format_string '%(color)s%(levelname)s %(name)s [%(global_request_id)s %(request_id)s %(project_name)s %(user_name)s%(color)s] %(instance)s%(color)s%(message)s'
+ functions:setup_systemd_logging:705      :   iniset /etc/keystone/keystone.conf DEFAULT logging_default_format_string '%(color)s%(levelname)s %(name)s [-%(color)s] %(instance)s%(color)s%(message)s'
+ functions:setup_systemd_logging:706      :   iniset /etc/keystone/keystone.conf DEFAULT logging_exception_prefix 'ERROR %(name)s %(instance)s'
+ lib/keystone:configure_keystone:257      :   iniset /etc/keystone/keystone.conf DEFAULT debug True
+ lib/keystone:configure_keystone:259      :   '[' uwsgi == mod_wsgi ']'
+ lib/keystone:configure_keystone:263      :   write_uwsgi_config /etc/keystone/keystone-uwsgi-public.ini /usr/local/bin/keystone-wsgi-public /identity
+ lib/apache:write_uwsgi_config:254        :   local file=/etc/keystone/keystone-uwsgi-public.ini
+ lib/apache:write_uwsgi_config:255        :   local wsgi=/usr/local/bin/keystone-wsgi-public
+ lib/apache:write_uwsgi_config:256        :   local url=/identity
... skipping 775 lines ...
+ functions:setup_systemd_logging:695      :   local pidstr=
+ functions:setup_systemd_logging:696      :   [[ False == \T\r\u\e ]]
+ functions:setup_systemd_logging:700      :   pidstr='(pid=%(process)d) '
+ functions:setup_systemd_logging:702      :   iniset /etc/glance/glance-api.conf DEFAULT logging_debug_format_suffix '{{(pid=%(process)d) %(funcName)s %(pathname)s:%(lineno)d}}'
+ functions:setup_systemd_logging:704      :   iniset /etc/glance/glance-api.conf DEFAULT logging_context_format_string '%(color)s%(levelname)s %(name)s [%(global_request_id)s %(request_id)s %(project_name)s %(user_name)s%(color)s] %(instance)s%(color)s%(message)s'
+ functions:setup_systemd_logging:705      :   iniset /etc/glance/glance-api.conf DEFAULT logging_default_format_string '%(color)s%(levelname)s %(name)s [-%(color)s] %(instance)s%(color)s%(message)s'
+ functions:setup_systemd_logging:706      :   iniset /etc/glance/glance-api.conf DEFAULT logging_exception_prefix 'ERROR %(name)s %(instance)s'
+ lib/glance:configure_glance:397          :   cp -p /opt/stack/glance/etc/glance-api-paste.ini /etc/glance/glance-api-paste.ini
+ lib/glance:configure_glance:400          :   iniset /etc/glance/glance-cache.conf DEFAULT debug True
+ lib/glance:configure_glance:401          :   iniset /etc/glance/glance-cache.conf DEFAULT use_syslog False
+ lib/glance:configure_glance:402          :   iniset /etc/glance/glance-cache.conf DEFAULT image_cache_dir /opt/stack/data/glance/cache/
+ lib/glance:configure_glance:403          :   iniset /etc/glance/glance-cache.conf DEFAULT auth_url http://10.0.2.15/identity
+ lib/glance:configure_glance:404          :   iniset /etc/glance/glance-cache.conf DEFAULT admin_tenant_name service
... skipping 825 lines ...
+ functions:setup_systemd_logging:695      :   local pidstr=
+ functions:setup_systemd_logging:696      :   [[ False == \T\r\u\e ]]
+ functions:setup_systemd_logging:700      :   pidstr='(pid=%(process)d) '
+ functions:setup_systemd_logging:702      :   iniset /etc/cinder/cinder.conf DEFAULT logging_debug_format_suffix '{{(pid=%(process)d) %(funcName)s %(pathname)s:%(lineno)d}}'
+ functions:setup_systemd_logging:704      :   iniset /etc/cinder/cinder.conf DEFAULT logging_context_format_string '%(color)s%(levelname)s %(name)s [%(global_request_id)s %(request_id)s %(project_name)s %(user_name)s%(color)s] %(instance)s%(color)s%(message)s'
+ functions:setup_systemd_logging:705      :   iniset /etc/cinder/cinder.conf DEFAULT logging_default_format_string '%(color)s%(levelname)s %(name)s [-%(color)s] %(instance)s%(color)s%(message)s'
+ functions:setup_systemd_logging:706      :   iniset /etc/cinder/cinder.conf DEFAULT logging_exception_prefix 'ERROR %(name)s %(instance)s'
+ lib/cinder:configure_cinder:351          :   write_uwsgi_config /etc/cinder/cinder-api-uwsgi.ini /usr/local/bin/cinder-wsgi /volume
+ lib/apache:write_uwsgi_config:254        :   local file=/etc/cinder/cinder-api-uwsgi.ini
+ lib/apache:write_uwsgi_config:255        :   local wsgi=/usr/local/bin/cinder-wsgi
+ lib/apache:write_uwsgi_config:256        :   local url=/volume
+ lib/apache:write_uwsgi_config:257        :   local http=
+ lib/apache:write_uwsgi_config:258        :   local name=
... skipping 2053 lines ...
+ functions:setup_systemd_logging:695      :   local pidstr=
+ functions:setup_systemd_logging:696      :   [[ False == \T\r\u\e ]]
+ functions:setup_systemd_logging:700      :   pidstr='(pid=%(process)d) '
+ functions:setup_systemd_logging:702      :   iniset /etc/nova/nova.conf DEFAULT logging_debug_format_suffix '{{(pid=%(process)d) %(funcName)s %(pathname)s:%(lineno)d}}'
+ functions:setup_systemd_logging:704      :   iniset /etc/nova/nova.conf DEFAULT logging_context_format_string '%(color)s%(levelname)s %(name)s [%(global_request_id)s %(request_id)s %(project_name)s %(user_name)s%(color)s] %(instance)s%(color)s%(message)s'
+ functions:setup_systemd_logging:705      :   iniset /etc/nova/nova.conf DEFAULT logging_default_format_string '%(color)s%(levelname)s %(name)s [-%(color)s] %(instance)s%(color)s%(message)s'
+ functions:setup_systemd_logging:706      :   iniset /etc/nova/nova.conf DEFAULT logging_exception_prefix 'ERROR %(name)s %(instance)s'
+ lib/nova:create_nova_conf:497            :   iniset /etc/nova/nova.conf upgrade_levels compute auto
+ lib/nova:create_nova_conf:499            :   write_uwsgi_config /etc/nova/nova-api-uwsgi.ini /usr/local/bin/nova-api-wsgi /compute
+ lib/apache:write_uwsgi_config:254        :   local file=/etc/nova/nova-api-uwsgi.ini
+ lib/apache:write_uwsgi_config:255        :   local wsgi=/usr/local/bin/nova-api-wsgi
+ lib/apache:write_uwsgi_config:256        :   local url=/compute
+ lib/apache:write_uwsgi_config:257        :   local http=
... skipping 194 lines ...
+ functions:setup_systemd_logging:695      :   local pidstr=
+ functions:setup_systemd_logging:696      :   [[ False == \T\r\u\e ]]
+ functions:setup_systemd_logging:700      :   pidstr='(pid=%(process)d) '
+ functions:setup_systemd_logging:702      :   iniset /etc/nova/nova_cell1.conf DEFAULT logging_debug_format_suffix '{{(pid=%(process)d) %(funcName)s %(pathname)s:%(lineno)d}}'
+ functions:setup_systemd_logging:704      :   iniset /etc/nova/nova_cell1.conf DEFAULT logging_context_format_string '%(color)s%(levelname)s %(name)s [%(global_request_id)s %(request_id)s %(project_name)s %(user_name)s%(color)s] %(instance)s%(color)s%(message)s'
+ functions:setup_systemd_logging:705      :   iniset /etc/nova/nova_cell1.conf DEFAULT logging_default_format_string '%(color)s%(levelname)s %(name)s [-%(color)s] %(instance)s%(color)s%(message)s'
+ functions:setup_systemd_logging:706      :   iniset /etc/nova/nova_cell1.conf DEFAULT logging_exception_prefix 'ERROR %(name)s %(instance)s'
+ lib/nova:create_nova_conf:563            :   [[ superconductor == \s\i\n\g\l\e\c\o\n\d\u\c\t\o\r ]]
++ lib/nova:create_nova_conf:566            :   seq 1 1
+ lib/nova:create_nova_conf:566            :   for i in $(seq 1 $NOVA_NUM_CELLS)
+ lib/nova:create_nova_conf:567            :   local conf
+ lib/nova:create_nova_conf:568            :   local offset
++ lib/nova:create_nova_conf:569            :   conductor_conf 1
... skipping 649 lines ...
+ functions:setup_systemd_logging:695      :   local pidstr=
+ functions:setup_systemd_logging:696      :   [[ False == \T\r\u\e ]]
+ functions:setup_systemd_logging:700      :   pidstr='(pid=%(process)d) '
+ functions:setup_systemd_logging:702      :   iniset /etc/placement/placement.conf DEFAULT logging_debug_format_suffix '{{(pid=%(process)d) %(funcName)s %(pathname)s:%(lineno)d}}'
+ functions:setup_systemd_logging:704      :   iniset /etc/placement/placement.conf DEFAULT logging_context_format_string '%(color)s%(levelname)s %(name)s [%(global_request_id)s %(request_id)s %(project_name)s %(user_name)s%(color)s] %(instance)s%(color)s%(message)s'
+ functions:setup_systemd_logging:705      :   iniset /etc/placement/placement.conf DEFAULT logging_default_format_string '%(color)s%(levelname)s %(name)s [-%(color)s] %(instance)s%(color)s%(message)s'
+ functions:setup_systemd_logging:706      :   iniset /etc/placement/placement.conf DEFAULT logging_exception_prefix 'ERROR %(name)s %(instance)s'
+ lib/placement:configure_placement:109    :   [[ uwsgi == \u\w\s\g\i ]]
+ lib/placement:configure_placement:110    :   write_uwsgi_config /etc/placement/placement-uwsgi.ini /usr/local/bin/placement-api /placement
+ lib/apache:write_uwsgi_config:254        :   local file=/etc/placement/placement-uwsgi.ini
+ lib/apache:write_uwsgi_config:255        :   local wsgi=/usr/local/bin/placement-api
+ lib/apache:write_uwsgi_config:256        :   local url=/placement
+ lib/apache:write_uwsgi_config:257        :   local http=
... skipping 318 lines ...
+ functions-common:is_opensuse:476         :   [[ -z Ubuntu ]]
+ functions-common:is_opensuse:480         :   [[ Ubuntu =~ (openSUSE) ]]
+ functions-common:is_suse:469             :   is_suse_linux_enterprise
+ functions-common:is_suse_linux_enterprise:488 :   [[ -z Ubuntu ]]
+ functions-common:is_suse_linux_enterprise:492 :   [[ Ubuntu =~ (^SUSE) ]]
+ lib/databases/mysql:configure_database_mysql:95 :   sudo mysqladmin -u root password password
mysqladmin: connect to server at 'localhost' failed
error: 'Access denied for user 'root'@'localhost' (using password: NO)'
+ lib/databases/mysql:configure_database_mysql:95 :   true
+ lib/databases/mysql:configure_database_mysql:99 :   is_ubuntu
+ functions-common:is_ubuntu:500           :   [[ -z deb ]]
+ functions-common:is_ubuntu:503           :   '[' deb = deb ']'
+ lib/databases/mysql:configure_database_mysql:99 :   '[' mysql == mariadb ']'
+ lib/databases/mysql:configure_database_mysql:102 :   local 'cmd_args=-uroot -ppassword -h127.0.0.1 '
... skipping 5849 lines ...
++ functions-common:get_or_create_user:847  :   local email=
+++ functions-common:get_or_create_user:861  :   oscwrap user create cinder --password '' --domain= --or-show -f value -c id
/usr/lib/python3/dist-packages/secretstorage/dhcrypto.py:15: CryptographyDeprecationWarning: int_from_bytes is deprecated, use int.from_bytes instead
  from cryptography.utils import int_from_bytes
/usr/lib/python3/dist-packages/secretstorage/util.py:19: CryptographyDeprecationWarning: int_from_bytes is deprecated, use int.from_bytes instead
  from cryptography.utils import int_from_bytes
No password was supplied, authentication will fail when a user does not have a password.
+++ functions-common:oscwrap:2382            :   return 0
++ functions-common:get_or_create_user:859  :   user_id=b4876b532f564b3f82dcf95d7500577c
++ functions-common:get_or_create_user:860  :   echo b4876b532f564b3f82dcf95d7500577c
+ lib/cinder:configure_cinder_internal_tenant:614 :   iniset /etc/cinder/cinder.conf DEFAULT cinder_internal_tenant_user_id b4876b532f564b3f82dcf95d7500577c
[8900 Async create_cinder_accounts:58185]: finished create_cinder_accounts with result 0 in 17 seconds
+ inc/async:async_wait:197                 :   return 0
... skipping 228 lines ...
+ functions:setup_systemd_logging:695      :   local pidstr=
+ functions:setup_systemd_logging:696      :   [[ False == \T\r\u\e ]]
+ functions:setup_systemd_logging:700      :   pidstr='(pid=%(process)d) '
+ functions:setup_systemd_logging:702      :   iniset /etc/neutron/neutron.conf DEFAULT logging_debug_format_suffix '{{(pid=%(process)d) %(funcName)s %(pathname)s:%(lineno)d}}'
+ functions:setup_systemd_logging:704      :   iniset /etc/neutron/neutron.conf DEFAULT logging_context_format_string '%(color)s%(levelname)s %(name)s [%(global_request_id)s %(request_id)s %(project_name)s %(user_name)s%(color)s] %(instance)s%(color)s%(message)s'
+ functions:setup_systemd_logging:705      :   iniset /etc/neutron/neutron.conf DEFAULT logging_default_format_string '%(color)s%(levelname)s %(name)s [-%(color)s] %(instance)s%(color)s%(message)s'
+ functions:setup_systemd_logging:706      :   iniset /etc/neutron/neutron.conf DEFAULT logging_exception_prefix 'ERROR %(name)s %(instance)s'
+ lib/neutron-legacy:_configure_neutron_common:800 :   is_service_enabled tls-proxy
+ functions-common:is_service_enabled:1998 :   return 1
+ lib/neutron-legacy:_configure_neutron_common:806 :   _neutron_setup_rootwrap
+ lib/neutron-legacy:_neutron_setup_rootwrap:949 :   [[ True == \F\a\l\s\e ]]
+ lib/neutron-legacy:_neutron_setup_rootwrap:953 :   Q_CONF_ROOTWRAP_D=/etc/neutron/rootwrap.d
+ lib/neutron-legacy:_neutron_setup_rootwrap:954 :   [[ -d /etc/neutron/rootwrap.d ]]
... skipping 177 lines ...
+ lib/neutron_plugins/openvswitch_agent:neutron_plugin_configure_plugin_agent:36 :   _neutron_ovs_base_setup_bridge br-int
+ lib/neutron_plugins/ovs_base:_neutron_ovs_base_setup_bridge:32 :   local bridge=br-int
+ lib/neutron_plugins/ovs_base:_neutron_ovs_base_setup_bridge:33 :   neutron-ovs-cleanup --config-file /etc/neutron/neutron.conf
INFO neutron.common.config [-] Logging enabled!
INFO neutron.common.config [-] /usr/local/bin/neutron-ovs-cleanup version 19.4.1.dev21
DEBUG neutron.common.config [-] command line: /usr/local/bin/neutron-ovs-cleanup --config-file /etc/neutron/neutron.conf {{(pid=63037) setup_logging /opt/stack/neutron/neutron/common/config.py:112}}
ERROR ovsdbapp.backend.ovs_idl.idlutils [-] Unable to open stream to tcp:127.0.0.1:6640 to retrieve schema: Connection refused
INFO oslo.privsep.daemon [-] Running privsep helper: ['sudo', '/usr/local/bin/neutron-rootwrap', '/etc/neutron/rootwrap.conf', 'privsep-helper', '--config-file', '/etc/neutron/neutron.conf', '--privsep_context', 'neutron.privileged.ovs_vsctl_cmd', '--privsep_sock_path', '/tmp/tmp5ot8wfpy/privsep.sock']
INFO oslo.privsep.daemon [-] Spawned new privsep daemon via rootwrap
DEBUG oslo.privsep.daemon [-] Accepted privsep connection to /tmp/tmp5ot8wfpy/privsep.sock {{(pid=63037) __init__ /usr/local/lib/python3.8/dist-packages/oslo_privsep/daemon.py:363}}
INFO oslo.privsep.daemon [-] privsep daemon starting
INFO oslo.privsep.daemon [-] privsep process running with uid/gid: 0/0
INFO oslo.privsep.daemon [-] privsep process running with capabilities (eff/prm/inh): CAP_NET_ADMIN|CAP_SYS_ADMIN/CAP_NET_ADMIN|CAP_SYS_ADMIN/none
... skipping 3031 lines ...
++ lib/neutron_plugins/services/l3:_neutron_get_ext_gw_interface:143 :   sudo ovs-vsctl set Bridge br-ex other_config:disable-in-band=true
++ lib/neutron_plugins/services/l3:_neutron_get_ext_gw_interface:145 :   echo br-ex
+ lib/neutron_plugins/services/l3:_neutron_configure_router_v4:337 :   ext_gw_interface=br-ex
+ lib/neutron_plugins/services/l3:_neutron_configure_router_v4:349 :   [[ br-ex != \n\o\n\e ]]
+ lib/neutron_plugins/services/l3:_neutron_configure_router_v4:350 :   local cidr_len=24
+ lib/neutron_plugins/services/l3:_neutron_configure_router_v4:351 :   local 'testcmd=ip -o link | grep -q br-ex'
+ lib/neutron_plugins/services/l3:_neutron_configure_router_v4:352 :   test_with_retry 'ip -o link | grep -q br-ex' 'br-ex creation failed'
+ functions-common:test_with_retry:2280    :   local 'testcmd=ip -o link | grep -q br-ex'
+ functions-common:test_with_retry:2281    :   local 'failmsg=br-ex creation failed'
+ functions-common:test_with_retry:2282    :   local until=10
+ functions-common:test_with_retry:2283    :   local sleep=0.5
+ functions-common:test_with_retry:2285    :   time_start test_with_retry
+ functions-common:time_start:2328         :   local name=test_with_retry
+ functions-common:time_start:2329         :   local start_time=
+ functions-common:time_start:2330         :   [[ -n '' ]]
... skipping 1958 lines ...
+ functions:wait_for_compute:493           :   [[ 0 != 0 ]]
+ functions:wait_for_compute:497           :   return 0
+ ./stack.sh:main:1442                     :   service_check
+ functions-common:service_check:1635      :   local service
+ functions-common:service_check:1636      :   for service in ${ENABLED_SERVICES//,/ }
+ functions-common:service_check:1638      :   sudo systemctl is-enabled devstack@rabbit.service
Failed to get unit file state for devstack@rabbit.service: No such file or directory
+ functions-common:service_check:1636      :   for service in ${ENABLED_SERVICES//,/ }
+ functions-common:service_check:1638      :   sudo systemctl is-enabled devstack@mysql.service
Failed to get unit file state for devstack@mysql.service: No such file or directory
+ functions-common:service_check:1636      :   for service in ${ENABLED_SERVICES//,/ }
+ functions-common:service_check:1638      :   sudo systemctl is-enabled devstack@key.service
Failed to get unit file state for devstack@key.service: No such file or directory
+ functions-common:service_check:1636      :   for service in ${ENABLED_SERVICES//,/ }
+ functions-common:service_check:1638      :   sudo systemctl is-enabled devstack@n-api.service
enabled
+ functions-common:service_check:1642      :   sudo systemctl status devstack@n-api.service --no-pager
● devstack@n-api.service - Devstack devstack@n-api.service
     Loaded: loaded (/etc/systemd/system/devstack@n-api.service; enabled; vendor preset: enabled)
... skipping 6 lines ...
             ├─69828 nova-apiuWSGI master
             ├─69829 nova-apiuWSGI worker 1
             └─69830 nova-apiuWSGI worker 2

Sep 06 00:37:35 devstack devstack@n-api.service[69830]: [pid: 69830|app: 0|req: 17/35] 10.0.2.15 () {64 vars in 1322 bytes} [Tue Sep  6 00:37:35 2022] POST /compute/v2.1/flavors/5/os-extra_specs => generated 43 bytes in 17 msecs (HTTP/1.1 200) 9 headers in 358 bytes (1 switches on core 0)
Sep 06 00:37:43 devstack devstack@n-api.service[69829]: DEBUG nova.api.openstack.wsgi [None req-30f5d4aa-8ca9-4a35-b30a-01c11aec3d99 admin admin] Calling method '<bound method ServiceController.index of <nova.api.openstack.compute.services.ServiceController object at 0x7f76cd7c7040>>' {{(pid=69829) _process_stack /opt/stack/nova/nova/api/openstack/wsgi.py:513}}
Sep 06 00:37:43 devstack devstack@n-api.service[69829]: /usr/local/lib/python3.8/dist-packages/oslo_policy/policy.py:1075: UserWarning: Policy os_compute_api:os-services:list failed scope check. The token used to make the request was project scoped but the policy requires ['system'] scope. This behavior may change in the future where using the intended scope is required
Sep 06 00:37:43 devstack devstack@n-api.service[69829]:   warnings.warn(msg)
Sep 06 00:37:43 devstack devstack@n-api.service[69829]: DEBUG oslo_concurrency.lockutils [None req-30f5d4aa-8ca9-4a35-b30a-01c11aec3d99 admin admin] Lock "00000000-0000-0000-0000-000000000000" acquired by "nova.context.set_target_cell.<locals>.get_or_set_cached_cell_and_set_connections" :: waited 0.000s {{(pid=69829) inner /usr/local/lib/python3.8/dist-packages/oslo_concurrency/lockutils.py:355}}
Sep 06 00:37:43 devstack devstack@n-api.service[69829]: DEBUG oslo_concurrency.lockutils [None req-30f5d4aa-8ca9-4a35-b30a-01c11aec3d99 admin admin] Lock "00000000-0000-0000-0000-000000000000" released by "nova.context.set_target_cell.<locals>.get_or_set_cached_cell_and_set_connections" :: held 0.000s {{(pid=69829) inner /usr/local/lib/python3.8/dist-packages/oslo_concurrency/lockutils.py:367}}
Sep 06 00:37:43 devstack devstack@n-api.service[69829]: DEBUG oslo_concurrency.lockutils [None req-30f5d4aa-8ca9-4a35-b30a-01c11aec3d99 admin admin] Lock "1e1e2665-8634-4b94-9370-5ad4c3ca887d" acquired by "nova.context.set_target_cell.<locals>.get_or_set_cached_cell_and_set_connections" :: waited 0.000s {{(pid=69829) inner /usr/local/lib/python3.8/dist-packages/oslo_concurrency/lockutils.py:355}}
Sep 06 00:37:43 devstack devstack@n-api.service[69829]: DEBUG oslo_concurrency.lockutils [None req-30f5d4aa-8ca9-4a35-b30a-01c11aec3d99 admin admin] Lock "1e1e2665-8634-4b94-9370-5ad4c3ca887d" released by "nova.context.set_target_cell.<locals>.get_or_set_cached_cell_and_set_connections" :: held 0.000s {{(pid=69829) inner /usr/local/lib/python3.8/dist-packages/oslo_concurrency/lockutils.py:367}}
Sep 06 00:37:43 devstack devstack@n-api.service[69829]: INFO nova.api.openstack.requestlog [None req-30f5d4aa-8ca9-4a35-b30a-01c11aec3d99 admin admin] 10.0.2.15 "GET /compute/v2.1/os-services?host=devstack&binary=nova-compute" status: 200 len: 192 microversion: 2.1 time: 0.046186
... skipping 20 lines ...
Sep 06 00:37:25 devstack nova-compute[77093]: DEBUG oslo_concurrency.lockutils [None req-0f2f933b-3673-4de3-9793-dd0ffbd10c3d None None] Lock "compute_resources" released by "nova.compute.resource_tracker.ResourceTracker._update_available_resource" :: held 0.336s {{(pid=77093) inner /usr/local/lib/python3.8/dist-packages/oslo_concurrency/lockutils.py:367}}
Sep 06 00:37:25 devstack nova-compute[77093]: DEBUG nova.service [None req-0f2f933b-3673-4de3-9793-dd0ffbd10c3d None None] Creating RPC server for service compute {{(pid=77093) start /opt/stack/nova/nova/service.py:182}}
Sep 06 00:37:25 devstack nova-compute[77093]: DEBUG nova.service [None req-0f2f933b-3673-4de3-9793-dd0ffbd10c3d None None] Join ServiceGroup membership for this service compute {{(pid=77093) start /opt/stack/nova/nova/service.py:199}}
Sep 06 00:37:25 devstack nova-compute[77093]: DEBUG nova.servicegroup.drivers.db [None req-0f2f933b-3673-4de3-9793-dd0ffbd10c3d None None] DB_Driver: join new ServiceGroup member devstack to the compute group, service = <Service: host=devstack, binary=nova-compute, manager_class_name=nova.compute.manager.ComputeManager> {{(pid=77093) join /opt/stack/nova/nova/servicegroup/drivers/db.py:44}}
+ functions-common:service_check:1636      :   for service in ${ENABLED_SERVICES//,/ }
+ functions-common:service_check:1638      :   sudo systemctl is-enabled devstack@n-cond.service
Failed to get unit file state for devstack@n-cond.service: No such file or directory
+ functions-common:service_check:1636      :   for service in ${ENABLED_SERVICES//,/ }
+ functions-common:service_check:1638      :   sudo systemctl is-enabled devstack@n-sch.service
enabled
+ functions-common:service_check:1642      :   sudo systemctl status devstack@n-sch.service --no-pager
● devstack@n-sch.service - Devstack devstack@n-sch.service
     Loaded: loaded (/etc/systemd/system/devstack@n-sch.service; enabled; vendor preset: enabled)
... skipping 68 lines ...
Sep 06 00:37:24 devstack devstack@placement-api.service[71040]: [pid: 71040|app: 0|req: 5/9] 10.0.2.15 () {60 vars in 3540 bytes} [Tue Sep  6 00:37:24 2022] GET /placement/traits?name=in:COMPUTE_VOLUME_ATTACH_WITH_TAG,COMPUTE_NET_VIF_MODEL_NE2K_PCI,COMPUTE_GRAPHICS_MODEL_NONE,COMPUTE_ACCELERATORS,COMPUTE_STORAGE_BUS_VIRTIO,COMPUTE_NET_ATTACH_INTERFACE_WITH_TAG,COMPUTE_SOCKET_PCI_NUMA_AFFINITY,COMPUTE_DEVICE_TAGGING,COMPUTE_STORAGE_BUS_FDC,COMPUTE_RESCUE_BFV,COMPUTE_NET_VIF_MODEL_VIRTIO,COMPUTE_VOLUME_MULTI_ATTACH,COMPUTE_GRAPHICS_MODEL_BOCHS,COMPUTE_STORAGE_BUS_SCSI,HW_CPU_X86_SVM,COMPUTE_IMAGE_TYPE_ARI,COMPUTE_STORAGE_BUS_IDE,COMPUTE_GRAPHICS_MODEL_VGA,COMPUTE_GRAPHICS_MODEL_QXL,COMPUTE_NET_VIF_MODEL_VMXNET3,HW_CPU_HYPERTHREADING,COMPUTE_NET_VIF_MODEL_SPAPR_VLAN,HW_CPU_X86_MMX,COMPUTE_VOLUME_EXTEND,HW_CPU_X86_SSE2,COMPUTE_SECURITY_UEFI_SECURE_BOOT,COMPUTE_GRAPHICS_MODEL_VIRTIO,COMPUTE_IMAGE_TYPE_AMI,COMPUTE_IMAGE_TYPE_RAW,COMPUTE_TRUSTED_CERTS,COMPUTE_NET_ATTACH_INTERFACE,COMPUTE_STORAGE_BUS_SATA,COMPUTE_GRAPHICS_MODEL_VMVGA,COMPUTE_NET_VIF_MODEL_RTL8139,COMPUTE_IMAGE_TYPE_ISO,COMPUTE_STORAGE_BUS_USB,COMPUTE_IMAGE_TYPE_QCOW2,HW_CPU_X86_SSE,COMPUTE_NET_VIF_MODEL_E1000,COMPUTE_NET_VIF_MODEL_E1000E,COMPUTE_NODE,COMPUTE_NET_VIF_MODEL_PCNET,HW_CPU_X86_AMD_SVM,COMPUTE_GRAPHICS_MODEL_CIRRUS,COMPUTE_IMAGE_TYPE_AKI => generated 1289 bytes in 11 msecs (HTTP/1.1 200) 6 headers in 225 bytes (1 switches on core 0)
Sep 06 00:37:24 devstack devstack@placement-api.service[71041]: DEBUG placement.requestlog [req-9c4b1618-a4d8-4e6e-8a9a-2e01099f332d req-ab39a7fc-71df-4bf9-9343-773df0c0f936 None None] Starting request: 10.0.2.15 "PUT /placement/resource_providers/4e45cf56-f867-4fb4-b597-a17f7b11721c/traits" {{(pid=71041) __call__ /opt/stack/placement/placement/requestlog.py:55}}
Sep 06 00:37:25 devstack devstack@placement-api.service[71041]: INFO placement.requestlog [req-9c4b1618-a4d8-4e6e-8a9a-2e01099f332d req-ab39a7fc-71df-4bf9-9343-773df0c0f936 service placement] 10.0.2.15 "PUT /placement/resource_providers/4e45cf56-f867-4fb4-b597-a17f7b11721c/traits" status: 200 len: 1324 microversion: 1.6
Sep 06 00:37:25 devstack devstack@placement-api.service[71041]: [pid: 71041|app: 0|req: 5/10] 10.0.2.15 () {64 vars in 1463 bytes} [Tue Sep  6 00:37:24 2022] PUT /placement/resource_providers/4e45cf56-f867-4fb4-b597-a17f7b11721c/traits => generated 1324 bytes in 49 msecs (HTTP/1.1 200) 6 headers in 225 bytes (1 switches on core 0)
+ functions-common:service_check:1636      :   for service in ${ENABLED_SERVICES//,/ }
+ functions-common:service_check:1638      :   sudo systemctl is-enabled devstack@placement-client.service
Failed to get unit file state for devstack@placement-client.service: No such file or directory
+ functions-common:service_check:1636      :   for service in ${ENABLED_SERVICES//,/ }
+ functions-common:service_check:1638      :   sudo systemctl is-enabled devstack@g-api.service
enabled
+ functions-common:service_check:1642      :   sudo systemctl status devstack@g-api.service --no-pager
● devstack@g-api.service - Devstack devstack@g-api.service
     Loaded: loaded (/etc/systemd/system/devstack@g-api.service; enabled; vendor preset: enabled)
... skipping 16 lines ...
Sep 06 00:37:34 devstack devstack@g-api.service[79556]: DEBUG glance_store._drivers.filesystem [None req-c8d6f391-7294-4de3-9ea7-d5ff9d7cbf0b admin admin] Wrote 16300544 bytes to /opt/stack/data/glance/images/b6655c23-1c81-49a8-8f40-73f8f8887705 with checksum b874c39491a2377b8490f5f1e89761a4 and multihash 6b813aa46bb90b4da216a4d19376593fa3f4fc7e617f03a92b7fe11e9a3981cbe8f0959dbebe36225e5f53dc4492341a4863cac4ed1ee0909f3fc78ef9c3e869 {{(pid=79556) add /usr/local/lib/python3.8/dist-packages/glance_store/_drivers/filesystem.py:773}}
Sep 06 00:37:34 devstack devstack@g-api.service[79556]: INFO glance.location [None req-c8d6f391-7294-4de3-9ea7-d5ff9d7cbf0b admin admin] Image format matched and virtual size computed: 117440512
Sep 06 00:37:34 devstack devstack@g-api.service[79556]: DEBUG glance_store.backend [None req-c8d6f391-7294-4de3-9ea7-d5ff9d7cbf0b admin admin] Skipping store.set_acls... not implemented. {{(pid=79556) set_acls /usr/local/lib/python3.8/dist-packages/glance_store/backend.py:509}}
Sep 06 00:37:34 devstack devstack@g-api.service[79556]: [pid: 79556|app: 0|req: 3/4] 127.0.0.1 () {40 vars in 856 bytes} [Tue Sep  6 00:37:33 2022] PUT /v2/images/b6655c23-1c81-49a8-8f40-73f8f8887705/file => generated 0 bytes in 864 msecs (HTTP/1.1 204) 4 headers in 171 bytes (1 switches on core 0)
+ functions-common:service_check:1636      :   for service in ${ENABLED_SERVICES//,/ }
+ functions-common:service_check:1638      :   sudo systemctl is-enabled devstack@g-reg.service
Failed to get unit file state for devstack@g-reg.service: No such file or directory
+ functions-common:service_check:1636      :   for service in ${ENABLED_SERVICES//,/ }
+ functions-common:service_check:1638      :   sudo systemctl is-enabled devstack@cinder.service
Failed to get unit file state for devstack@cinder.service: No such file or directory
+ functions-common:service_check:1636      :   for service in ${ENABLED_SERVICES//,/ }
+ functions-common:service_check:1638      :   sudo systemctl is-enabled devstack@c-api.service
enabled
+ functions-common:service_check:1642      :   sudo systemctl status devstack@c-api.service --no-pager
● devstack@c-api.service - Devstack devstack@c-api.service
     Loaded: loaded (/etc/systemd/system/devstack@c-api.service; enabled; vendor preset: enabled)
... skipping 1694 lines ...
    "port": 22,
    "search_regex": "OpenSSH",
    "state": "started"
}

TASK [install-k3s : Wait until k3s installation is finished] *******************
FAILED - RETRYING: Wait until k3s installation is finished (100 retries left).
FAILED - RETRYING: Wait until k3s installation is finished (99 retries left).
FAILED - RETRYING: Wait until k3s installation is finished (98 retries left).
FAILED - RETRYING: Wait until k3s installation is finished (97 retries left).
FAILED - RETRYING: Wait until k3s installation is finished (96 retries left).
FAILED - RETRYING: Wait until k3s installation is finished (95 retries left).
FAILED - RETRYING: Wait until k3s installation is finished (94 retries left).
FAILED - RETRYING: Wait until k3s installation is finished (93 retries left).
FAILED - RETRYING: Wait until k3s installation is finished (92 retries left).
FAILED - RETRYING: Wait until k3s installation is finished (91 retries left).
changed: [34.150.148.63] => {
    "attempts": 11,
    "changed": true,
    "cmd": "ssh -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -i /root/.ssh/id_rsa ubuntu@172.24.5.198 sudo chmod 777 /etc/rancher/k3s/k3s.yaml\n",
    "delta": "0:00:00.559111",
    "end": "2022-09-06 00:40:39.720816",
... skipping 29 lines ...
+ curl -sLO# https://storage.googleapis.com/kubernetes-release/release/v1.25.0/bin/linux/amd64/kubectl
+ chmod +x ./kubectl
+ sudo mv ./kubectl /usr/local/bin/kubectl
+ kubectl config set-cluster default --server=https://172.24.5.198:6443 --kubeconfig /root/.kube/config

TASK [install-k3s : Wait for k8s node ready] ***********************************
FAILED - RETRYING: Wait for k8s node ready (12 retries left).
changed: [34.150.148.63] => {
    "attempts": 2,
    "changed": true,
    "cmd": "kubectl --kubeconfig /root/.kube/config get node | grep \" Ready \" | wc -l\n",
    "delta": "0:00:00.057607",
    "end": "2022-09-06 00:40:53.145144",
... skipping 424 lines ...
STDERR:

+ cat
+ kubectl apply -f -

TASK [install-cpo-occm : Wait for openstack-cloud-controller-manager up and running] ***
FAILED - RETRYING: Wait for openstack-cloud-controller-manager up and running (24 retries left).
changed: [34.150.148.63] => {
    "attempts": 2,
    "changed": true,
    "cmd": "kubectl -n kube-system get pod | grep openstack-cloud-controller-manager | grep Running\n",
    "delta": "0:00:00.060946",
    "end": "2022-09-06 00:42:07.960052",
... skipping 2 lines ...
}

STDOUT:

openstack-cloud-controller-manager-5cddbdf8bc-dwfmf   1/1     Running   0          6s

TASK [install-cpo-occm : Describe failed openstack-cloud-controller-manager] ***
skipping: [34.150.148.63] => {
    "changed": false,
    "skip_reason": "Conditional result was False"
}

TASK [install-cpo-occm : Log failed openstack-cloud-controller-manager deployment] ***
skipping: [34.150.148.63] => {}

TASK [install-cpo-occm : Show openstack-cloud-controller-manager pod logs] *****
skipping: [34.150.148.63] => {
    "changed": false,
    "skip_reason": "Conditional result was False"
... skipping 564 lines ...
clusterrole.rbac.authorization.k8s.io/snapshot-controller-runner created
rolebinding.rbac.authorization.k8s.io/snapshot-controller-leaderelection created
clusterrolebinding.rbac.authorization.k8s.io/snapshot-controller-role created
deployment.apps/snapshot-controller created

TASK [install-csi-cinder : Wait for csi-cinder-controllerplugin up and running] ***
FAILED - RETRYING: Wait for csi-cinder-controllerplugin up and running (24 retries left).
FAILED - RETRYING: Wait for csi-cinder-controllerplugin up and running (23 retries left).
FAILED - RETRYING: Wait for csi-cinder-controllerplugin up and running (22 retries left).
FAILED - RETRYING: Wait for csi-cinder-controllerplugin up and running (21 retries left).
changed: [34.150.148.63] => {
    "attempts": 5,
    "changed": true,
    "cmd": "kubectl -n kube-system get pod | grep csi-cinder-controllerplugin  | grep Running\n",
    "delta": "0:00:00.064584",
    "end": "2022-09-06 00:43:48.251776",
... skipping 33 lines ...

STDOUT:

snapshot-controller-7f5d798964-kk8bk                  1/1     Running   0          27s
snapshot-controller-7f5d798964-8zhnt                  1/1     Running   0          27s

TASK [install-csi-cinder : Describe failed csi-cinder-plugin] ******************
skipping: [34.150.148.63] => {
    "changed": false,
    "skip_reason": "Conditional result was False"
}

TASK [install-csi-cinder : Log failed csi-cinder-plugin deployment] ************
skipping: [34.150.148.63] => {}

TASK [install-csi-cinder : Stop due to prior failure of csi-cinder-plugin] *****
skipping: [34.150.148.63] => {
    "changed": false,
    "skip_reason": "Conditional result was False"
... skipping 31 lines ...
    "uid": 0
}

TASK [install-csi-cinder : Run functional tests for csi-cinder-plugin] *********
changed: [34.150.148.63] => {
    "changed": true,
    "cmd": "set -x\nset -e\nset -o pipefail\n\ncd $GOPATH/src/k8s.io/cloud-provider-openstack\nmkdir -p /var/log/csi-pod\n# TODO(chrigl): No idea why both tests fail in CI. On a real OpenStack both pass.\n/tmp/kubernetes/test/bin/e2e.test \\\n  -storage.testdriver=tests/e2e/csi/cinder/test-driver.yaml \\\n  -ginkgo.focus='External.Storage' \\\n  -ginkgo.skip='\\[Disruptive\\]|\\[Testpattern:\\s+Dynamic\\s+PV\\s+\\(default\\s+fs\\)\\]\\s+provisioning\\s+should\\s+mount\\s+multiple\\s+PV\\s+pointing\\s+to\\s+the\\s+same\\s+storage\\s+on\\s+the\\s+same\\s+node|\\[Testpattern:\\s+Dynamic\\s+PV\\s+\\(default\\s+fs\\)\\]\\s+provisioning\\s+should\\s+provision\\s+storage\\s+with\\s+any\\s+volume\\s+data\\s+source\\s+\\[Serial\\]' \\\n  -ginkgo.noColor \\\n  -ginkgo.progress \\\n  -ginkgo.v \\\n  -test.timeout=0 \\\n  -report-dir=\"/var/log/csi-pod\" | tee \"/var/log/csi-pod/cinder-csi-e2e.log\"\n",
    "delta": "1:22:43.479071",
    "end": "2022-09-06 02:06:55.501159",
    "rc": 0,
    "start": "2022-09-06 00:44:12.022088"
}

STDOUT:

Sep  6 00:44:12.095: INFO: Driver loaded from path [tests/e2e/csi/cinder/test-driver.yaml]: &{DriverInfo:{Name:cinder.csi.openstack.org InTreePluginName: FeatureTag: MaxFileSize:0 SupportedSizeRange:{Max: Min:1Gi} SupportedFsType:map[:{} ext2:{} ext3:{} ext4:{} xfs:{}] SupportedMountOption:map[] RequiredMountOption:map[] Capabilities:map[block:true controllerExpansion:true exec:true fsGroup:true multipods:true nodeExpansion:true onlineExpansion:true persistence:true pvcDataSource:true snapshotDataSource:true topology:true] RequiredAccessModes:[] TopologyKeys:[topology.cinder.csi.openstack.org/zone] NumAllowedTopologies:0 StressTestOptions:<nil> VolumeSnapshotStressTestOptions:<nil> PerformanceTestOptions:<nil>} StorageClass:{FromName:true FromFile: FromExistingClassName:} SnapshotClass:{FromName:true FromFile: FromExistingClassName:} InlineVolumes:[] ClientNodeName: Timeouts:map[]}
Sep  6 00:44:12.095: INFO: The --provider flag is not set. Continuing as if --provider=skeleton had been used.
{"msg":"Test Suite starting","total":244,"completed":0,"skipped":0,"failed":0}
Running Suite: Kubernetes e2e suite
===================================
Random Seed: 1662425052 - Will randomize all specs
Will run 244 of 7227 specs

Sep  6 00:44:13.562: INFO: >>> kubeConfig: /root/.kube/config
... skipping 317 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should concurrently access the single volume from pods on the same node
    test/e2e/storage/testsuites/multivolume.go:298
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow] should concurrently access the single volume from pods on the same node","total":244,"completed":1,"skipped":391,"failed":0}
SSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (filesystem volmode)] multiVolume [Slow] 
  should access to two volumes with the same volume mode and retain data across pod recreation on different node
  test/e2e/storage/testsuites/multivolume.go:168
[BeforeEach] [Testpattern: Pre-provisioned PV (filesystem volmode)] multiVolume [Slow]
... skipping 83 lines ...

    test/e2e/storage/external/external.go:262
------------------------------
SSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (default fs)] subPath 
  should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:280
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
Sep  6 00:45:06.481: INFO: Driver "cinder.csi.openstack.org" does not support volume type "PreprovisionedPV" - skipping
[AfterEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/framework/framework.go:188

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: cinder.csi.openstack.org]
test/e2e/storage/external/external.go:174
  [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly] [BeforeEach]
    test/e2e/storage/testsuites/subpath.go:280

    Driver "cinder.csi.openstack.org" does not support volume type "PreprovisionedPV" - skipping

    test/e2e/storage/external/external.go:262
------------------------------
... skipping 20 lines ...

    test/e2e/storage/external/external.go:262
------------------------------
SSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath 
  should fail if subpath file is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:258
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  test/e2e/storage/framework/testsuite.go:51
Sep  6 00:45:06.483: INFO: Driver cinder.csi.openstack.org doesn't support ntfs -- skipping
[AfterEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  test/e2e/framework/framework.go:188

S [SKIPPING] in Spec Setup (BeforeEach) [0.000 seconds]
External Storage [Driver: cinder.csi.openstack.org]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath file is outside the volume [Slow][LinuxOnly] [BeforeEach]
    test/e2e/storage/testsuites/subpath.go:258

    Driver cinder.csi.openstack.org doesn't support ntfs -- skipping

    test/e2e/storage/framework/testsuite.go:121
------------------------------
... skipping 20 lines ...
Sep  6 00:45:06.540: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  6 00:45:06.549: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgwdb9p] to have phase Bound
Sep  6 00:45:06.563: INFO: PersistentVolumeClaim cinder.csi.openstack.orgwdb9p found but phase is Pending instead of Bound.
Sep  6 00:45:08.567: INFO: PersistentVolumeClaim cinder.csi.openstack.orgwdb9p found and phase=Bound (2.018221559s)
STEP: [init] starting a pod to use the claim
STEP: [init] check pod success
Sep  6 00:45:08.587: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-jl5k4" in namespace "snapshotting-4197" to be "Succeeded or Failed"
Sep  6 00:45:08.589: INFO: Pod "pvc-snapshottable-tester-jl5k4": Phase="Pending", Reason="", readiness=false. Elapsed: 2.271184ms
Sep  6 00:45:10.594: INFO: Pod "pvc-snapshottable-tester-jl5k4": Phase="Pending", Reason="", readiness=false. Elapsed: 2.006532846s
Sep  6 00:45:12.600: INFO: Pod "pvc-snapshottable-tester-jl5k4": Phase="Pending", Reason="", readiness=false. Elapsed: 4.012559859s
Sep  6 00:45:14.605: INFO: Pod "pvc-snapshottable-tester-jl5k4": Phase="Pending", Reason="", readiness=false. Elapsed: 6.017955078s
Sep  6 00:45:16.609: INFO: Pod "pvc-snapshottable-tester-jl5k4": Phase="Pending", Reason="", readiness=false. Elapsed: 8.021644797s
Sep  6 00:45:18.614: INFO: Pod "pvc-snapshottable-tester-jl5k4": Phase="Pending", Reason="", readiness=false. Elapsed: 10.026938528s
Sep  6 00:45:20.622: INFO: Pod "pvc-snapshottable-tester-jl5k4": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.034857926s
STEP: Saw pod success
Sep  6 00:45:20.622: INFO: Pod "pvc-snapshottable-tester-jl5k4" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
Sep  6 00:45:20.625: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgwdb9p] to have phase Bound
Sep  6 00:45:20.630: INFO: PersistentVolumeClaim cinder.csi.openstack.orgwdb9p found and phase=Bound (4.332713ms)
STEP: [init] checking the PV
STEP: [init] deleting the pod
Sep  6 00:45:20.652: INFO: Pod pvc-snapshottable-tester-jl5k4 has the following logs: 
... skipping 37 lines ...
Sep  6 00:45:34.818: INFO: WaitUntil finished successfully after 2.010246141s
STEP: getting the snapshot and snapshot content
STEP: checking the snapshot
STEP: checking the SnapshotContent
STEP: Modifying source data test
STEP: modifying the data in the source PVC
Sep  6 00:45:34.839: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-data-tester-dvm54" in namespace "snapshotting-4197" to be "Succeeded or Failed"
Sep  6 00:45:34.858: INFO: Pod "pvc-snapshottable-data-tester-dvm54": Phase="Pending", Reason="", readiness=false. Elapsed: 19.03119ms
Sep  6 00:45:36.864: INFO: Pod "pvc-snapshottable-data-tester-dvm54": Phase="Pending", Reason="", readiness=false. Elapsed: 2.02453242s
Sep  6 00:45:38.870: INFO: Pod "pvc-snapshottable-data-tester-dvm54": Phase="Pending", Reason="", readiness=false. Elapsed: 4.031442571s
Sep  6 00:45:40.874: INFO: Pod "pvc-snapshottable-data-tester-dvm54": Phase="Pending", Reason="", readiness=false. Elapsed: 6.034716065s
Sep  6 00:45:42.878: INFO: Pod "pvc-snapshottable-data-tester-dvm54": Phase="Pending", Reason="", readiness=false. Elapsed: 8.039005011s
Sep  6 00:45:44.882: INFO: Pod "pvc-snapshottable-data-tester-dvm54": Phase="Pending", Reason="", readiness=false. Elapsed: 10.043015003s
Sep  6 00:45:46.887: INFO: Pod "pvc-snapshottable-data-tester-dvm54": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.047714398s
STEP: Saw pod success
Sep  6 00:45:46.887: INFO: Pod "pvc-snapshottable-data-tester-dvm54" satisfied condition "Succeeded or Failed"
Sep  6 00:45:46.897: INFO: Pod pvc-snapshottable-data-tester-dvm54 has the following logs: 
Sep  6 00:45:46.897: INFO: Deleting pod "pvc-snapshottable-data-tester-dvm54" in namespace "snapshotting-4197"
Sep  6 00:45:46.907: INFO: Wait up to 5m0s for pod "pvc-snapshottable-data-tester-dvm54" to be fully deleted
STEP: creating a pvc from the snapshot
STEP: starting a pod to use the snapshot
Sep  6 00:45:58.975: INFO: Running '/usr/local/bin/kubectl --server=https://172.24.5.198:6443 --kubeconfig=/root/.kube/config --namespace=snapshotting-4197 exec restored-pvc-tester-pm546 --namespace=snapshotting-4197 -- cat /mnt/test/data'
... skipping 35 lines ...
Sep  6 00:46:23.380: INFO: volumesnapshotcontents pre-provisioned-snapcontent-aad910ad-2062-4653-bfb9-661bc0469ba2 has been found and is not deleted
Sep  6 00:46:24.385: INFO: volumesnapshotcontents pre-provisioned-snapcontent-aad910ad-2062-4653-bfb9-661bc0469ba2 has been found and is not deleted
Sep  6 00:46:25.391: INFO: volumesnapshotcontents pre-provisioned-snapcontent-aad910ad-2062-4653-bfb9-661bc0469ba2 has been found and is not deleted
Sep  6 00:46:26.396: INFO: volumesnapshotcontents pre-provisioned-snapcontent-aad910ad-2062-4653-bfb9-661bc0469ba2 has been found and is not deleted
Sep  6 00:46:27.400: INFO: volumesnapshotcontents pre-provisioned-snapcontent-aad910ad-2062-4653-bfb9-661bc0469ba2 has been found and is not deleted
Sep  6 00:46:28.404: INFO: volumesnapshotcontents pre-provisioned-snapcontent-aad910ad-2062-4653-bfb9-661bc0469ba2 has been found and is not deleted
Sep  6 00:46:29.405: INFO: WaitUntil failed after reaching the timeout 30s
[AfterEach] volume snapshot controller
  test/e2e/storage/testsuites/snapshottable.go:172
Sep  6 00:46:29.413: INFO: Pod restored-pvc-tester-pm546 has the following logs: 
Sep  6 00:46:29.413: INFO: Deleting pod "restored-pvc-tester-pm546" in namespace "snapshotting-4197"
Sep  6 00:46:29.416: INFO: Wait up to 5m0s for pod "restored-pvc-tester-pm546" to be fully deleted
Sep  6 00:46:33.424: INFO: deleting claim "snapshotting-4197"/"pvc-46hml"
... skipping 27 lines ...
    test/e2e/storage/testsuites/snapshottable.go:113
      
      test/e2e/storage/testsuites/snapshottable.go:176
        should check snapshot fields, check restore correctly works after modifying source data, check deletion (persistent)
        test/e2e/storage/testsuites/snapshottable.go:278
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned Snapshot (retain policy)] snapshottable[Feature:VolumeSnapshotDataSource] volume snapshot controller  should check snapshot fields, check restore correctly works after modifying source data, check deletion (persistent)","total":244,"completed":2,"skipped":579,"failed":0}
SS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath 
  should support existing directory
  test/e2e/storage/testsuites/subpath.go:207
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
... skipping 14 lines ...
Sep  6 00:46:40.558: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  6 00:46:40.567: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgqc4v2] to have phase Bound
Sep  6 00:46:40.574: INFO: PersistentVolumeClaim cinder.csi.openstack.orgqc4v2 found but phase is Pending instead of Bound.
Sep  6 00:46:42.579: INFO: PersistentVolumeClaim cinder.csi.openstack.orgqc4v2 found and phase=Bound (2.011879481s)
STEP: Creating pod pod-subpath-test-dynamicpv-s924
STEP: Creating a pod to test subpath
Sep  6 00:46:42.592: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-s924" in namespace "provisioning-4664" to be "Succeeded or Failed"
Sep  6 00:46:42.599: INFO: Pod "pod-subpath-test-dynamicpv-s924": Phase="Pending", Reason="", readiness=false. Elapsed: 6.821522ms
Sep  6 00:46:44.605: INFO: Pod "pod-subpath-test-dynamicpv-s924": Phase="Pending", Reason="", readiness=false. Elapsed: 2.012919631s
Sep  6 00:46:46.610: INFO: Pod "pod-subpath-test-dynamicpv-s924": Phase="Pending", Reason="", readiness=false. Elapsed: 4.018063541s
Sep  6 00:46:48.615: INFO: Pod "pod-subpath-test-dynamicpv-s924": Phase="Pending", Reason="", readiness=false. Elapsed: 6.023258696s
Sep  6 00:46:50.624: INFO: Pod "pod-subpath-test-dynamicpv-s924": Phase="Pending", Reason="", readiness=false. Elapsed: 8.032204473s
Sep  6 00:46:52.629: INFO: Pod "pod-subpath-test-dynamicpv-s924": Phase="Pending", Reason="", readiness=false. Elapsed: 10.036783662s
Sep  6 00:46:54.641: INFO: Pod "pod-subpath-test-dynamicpv-s924": Phase="Pending", Reason="", readiness=false. Elapsed: 12.049321823s
Sep  6 00:46:56.647: INFO: Pod "pod-subpath-test-dynamicpv-s924": Phase="Pending", Reason="", readiness=false. Elapsed: 14.054676697s
Sep  6 00:46:58.652: INFO: Pod "pod-subpath-test-dynamicpv-s924": Phase="Pending", Reason="", readiness=false. Elapsed: 16.05982475s
Sep  6 00:47:00.657: INFO: Pod "pod-subpath-test-dynamicpv-s924": Phase="Pending", Reason="", readiness=false. Elapsed: 18.06468181s
Sep  6 00:47:02.662: INFO: Pod "pod-subpath-test-dynamicpv-s924": Phase="Succeeded", Reason="", readiness=false. Elapsed: 20.07032218s
STEP: Saw pod success
Sep  6 00:47:02.662: INFO: Pod "pod-subpath-test-dynamicpv-s924" satisfied condition "Succeeded or Failed"
Sep  6 00:47:02.665: INFO: Trying to get logs from node k3s-master pod pod-subpath-test-dynamicpv-s924 container test-container-volume-dynamicpv-s924: <nil>
STEP: delete the pod
Sep  6 00:47:02.686: INFO: Waiting for pod pod-subpath-test-dynamicpv-s924 to disappear
Sep  6 00:47:02.691: INFO: Pod pod-subpath-test-dynamicpv-s924 no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-s924
Sep  6 00:47:02.691: INFO: Deleting pod "pod-subpath-test-dynamicpv-s924" in namespace "provisioning-4664"
... skipping 18 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should support existing directory
    test/e2e/storage/testsuites/subpath.go:207
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath should support existing directory","total":244,"completed":3,"skipped":581,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath 
  should fail if subpath file is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:258
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/framework/framework.go:187
STEP: Creating a kubernetes client
Sep  6 00:47:22.772: INFO: >>> kubeConfig: /root/.kube/config
STEP: Building a namespace api object, basename provisioning
STEP: Waiting for a default service account to be provisioned in namespace
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
[It] should fail if subpath file is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:258
Sep  6 00:47:22.824: INFO: Creating resource for dynamic PV
Sep  6 00:47:22.824: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(cinder.csi.openstack.org) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-693-e2e-scb5qn8
STEP: creating a claim
Sep  6 00:47:22.837: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  6 00:47:22.855: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgpl5jp] to have phase Bound
Sep  6 00:47:22.866: INFO: PersistentVolumeClaim cinder.csi.openstack.orgpl5jp found but phase is Pending instead of Bound.
Sep  6 00:47:24.871: INFO: PersistentVolumeClaim cinder.csi.openstack.orgpl5jp found and phase=Bound (2.016411374s)
STEP: Creating pod pod-subpath-test-dynamicpv-zrgb
STEP: Checking for subpath error in container status
Sep  6 00:47:34.898: INFO: Deleting pod "pod-subpath-test-dynamicpv-zrgb" in namespace "provisioning-693"
Sep  6 00:47:34.903: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-zrgb" to be fully deleted
STEP: Deleting pod
Sep  6 00:47:36.912: INFO: Deleting pod "pod-subpath-test-dynamicpv-zrgb" in namespace "provisioning-693"
STEP: Deleting pvc
Sep  6 00:47:36.915: INFO: Deleting PersistentVolumeClaim "cinder.csi.openstack.orgpl5jp"
... skipping 9 lines ...

• [SLOW TEST:24.182 seconds]
External Storage [Driver: cinder.csi.openstack.org]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath file is outside the volume [Slow][LinuxOnly]
    test/e2e/storage/testsuites/subpath.go:258
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath should fail if subpath file is outside the volume [Slow][LinuxOnly]","total":244,"completed":4,"skipped":616,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ext4)] multiVolume [Slow] 
  should access to two volumes with different volume mode and retain data across pod recreation on the same node
  test/e2e/storage/testsuites/multivolume.go:209
[BeforeEach] [Testpattern: Dynamic PV (ext4)] multiVolume [Slow]
... skipping 179 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (ext4)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should access to two volumes with different volume mode and retain data across pod recreation on the same node
    test/e2e/storage/testsuites/multivolume.go:209
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ext4)] multiVolume [Slow] should access to two volumes with different volume mode and retain data across pod recreation on the same node","total":244,"completed":5,"skipped":668,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral 
  should create read/write inline ephemeral volume
  test/e2e/storage/testsuites/ephemeral.go:196
[BeforeEach] [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral
... skipping 38 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral
  test/e2e/storage/framework/testsuite.go:50
    should create read/write inline ephemeral volume
    test/e2e/storage/testsuites/ephemeral.go:196
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral should create read/write inline ephemeral volume","total":244,"completed":6,"skipped":712,"failed":0}
SSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] 
  should access to two volumes with different volume mode and retain data across pod recreation on different node
  test/e2e/storage/testsuites/multivolume.go:248
[BeforeEach] [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow]
... skipping 150 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] provisioning
  test/e2e/storage/framework/testsuite.go:50
    should provision storage with pvc data source
    test/e2e/storage/testsuites/provisioning.go:421
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] provisioning should provision storage with pvc data source","total":244,"completed":7,"skipped":781,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (block volmode)] volumeMode 
  should not mount / map unused volumes in a pod [LinuxOnly]
  test/e2e/storage/testsuites/volumemode.go:354
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
... skipping 52 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (block volmode)] volumeMode
  test/e2e/storage/framework/testsuite.go:50
    should not mount / map unused volumes in a pod [LinuxOnly]
    test/e2e/storage/testsuites/volumemode.go:354
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (block volmode)] volumeMode should not mount / map unused volumes in a pod [LinuxOnly]","total":244,"completed":8,"skipped":825,"failed":0}
SSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: CSI Ephemeral-volume (default fs)] ephemeral 
  should support multiple inline ephemeral volumes
  test/e2e/storage/testsuites/ephemeral.go:254
[BeforeEach] [Testpattern: CSI Ephemeral-volume (default fs)] ephemeral
... skipping 14 lines ...

    test/e2e/storage/external/external.go:262
------------------------------
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (block volmode)] volumeMode 
  should fail to use a volume in a pod with mismatched mode [Slow]
  test/e2e/storage/testsuites/volumemode.go:299
[BeforeEach] [Testpattern: Pre-provisioned PV (block volmode)] volumeMode
  test/e2e/storage/framework/testsuite.go:51
Sep  6 00:51:20.104: INFO: Driver "cinder.csi.openstack.org" does not support volume type "PreprovisionedPV" - skipping
[AfterEach] [Testpattern: Pre-provisioned PV (block volmode)] volumeMode
  test/e2e/framework/framework.go:188

S [SKIPPING] in Spec Setup (BeforeEach) [0.000 seconds]
External Storage [Driver: cinder.csi.openstack.org]
test/e2e/storage/external/external.go:174
  [Testpattern: Pre-provisioned PV (block volmode)] volumeMode
  test/e2e/storage/framework/testsuite.go:50
    should fail to use a volume in a pod with mismatched mode [Slow] [BeforeEach]
    test/e2e/storage/testsuites/volumemode.go:299

    Driver "cinder.csi.openstack.org" does not support volume type "PreprovisionedPV" - skipping

    test/e2e/storage/external/external.go:262
------------------------------
... skipping 100 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (block volmode)(allowExpansion)] volume-expand
  test/e2e/storage/framework/testsuite.go:50
    Verify if offline PVC expansion works
    test/e2e/storage/testsuites/volume_expand.go:176
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (block volmode)(allowExpansion)] volume-expand Verify if offline PVC expansion works","total":244,"completed":9,"skipped":1046,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Inline-volume (ntfs)][Feature:Windows] volumes 
  should store data
  test/e2e/storage/testsuites/volumes.go:161
[BeforeEach] [Testpattern: Inline-volume (ntfs)][Feature:Windows] volumes
... skipping 75 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (filesystem volmode)] volumeMode
  test/e2e/storage/framework/testsuite.go:50
    should not mount / map unused volumes in a pod [LinuxOnly]
    test/e2e/storage/testsuites/volumemode.go:354
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (filesystem volmode)] volumeMode should not mount / map unused volumes in a pod [LinuxOnly]","total":244,"completed":10,"skipped":1279,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] volumes 
  should store data
  test/e2e/storage/testsuites/volumes.go:161
[BeforeEach] [Testpattern: Dynamic PV (default fs)] volumes
... skipping 89 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] volumes
  test/e2e/storage/framework/testsuite.go:50
    should store data
    test/e2e/storage/testsuites/volumes.go:161
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] volumes should store data","total":244,"completed":11,"skipped":1308,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ext4)] multiVolume [Slow] 
  should access to two volumes with the same volume mode and retain data across pod recreation on the same node
  test/e2e/storage/testsuites/multivolume.go:138
[BeforeEach] [Testpattern: Dynamic PV (ext4)] multiVolume [Slow]
... skipping 178 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (ext4)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should access to two volumes with the same volume mode and retain data across pod recreation on the same node
    test/e2e/storage/testsuites/multivolume.go:138
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ext4)] multiVolume [Slow] should access to two volumes with the same volume mode and retain data across pod recreation on the same node","total":244,"completed":12,"skipped":1340,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath 
  should support readOnly directory specified in the volumeMount
  test/e2e/storage/testsuites/subpath.go:367
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
... skipping 14 lines ...
Sep  6 00:53:36.756: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  6 00:53:36.773: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.org6gk26] to have phase Bound
Sep  6 00:53:36.784: INFO: PersistentVolumeClaim cinder.csi.openstack.org6gk26 found but phase is Pending instead of Bound.
Sep  6 00:53:38.791: INFO: PersistentVolumeClaim cinder.csi.openstack.org6gk26 found and phase=Bound (2.017984817s)
STEP: Creating pod pod-subpath-test-dynamicpv-bfw8
STEP: Creating a pod to test subpath
Sep  6 00:53:38.804: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-bfw8" in namespace "provisioning-7402" to be "Succeeded or Failed"
Sep  6 00:53:38.811: INFO: Pod "pod-subpath-test-dynamicpv-bfw8": Phase="Pending", Reason="", readiness=false. Elapsed: 7.294972ms
Sep  6 00:53:40.816: INFO: Pod "pod-subpath-test-dynamicpv-bfw8": Phase="Pending", Reason="", readiness=false. Elapsed: 2.012307824s
Sep  6 00:53:42.821: INFO: Pod "pod-subpath-test-dynamicpv-bfw8": Phase="Pending", Reason="", readiness=false. Elapsed: 4.016523812s
Sep  6 00:53:44.828: INFO: Pod "pod-subpath-test-dynamicpv-bfw8": Phase="Pending", Reason="", readiness=false. Elapsed: 6.02372973s
Sep  6 00:53:46.834: INFO: Pod "pod-subpath-test-dynamicpv-bfw8": Phase="Pending", Reason="", readiness=false. Elapsed: 8.029992207s
Sep  6 00:53:48.839: INFO: Pod "pod-subpath-test-dynamicpv-bfw8": Phase="Pending", Reason="", readiness=false. Elapsed: 10.034867668s
Sep  6 00:53:50.844: INFO: Pod "pod-subpath-test-dynamicpv-bfw8": Phase="Pending", Reason="", readiness=false. Elapsed: 12.039538938s
Sep  6 00:53:52.849: INFO: Pod "pod-subpath-test-dynamicpv-bfw8": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.045002167s
STEP: Saw pod success
Sep  6 00:53:52.849: INFO: Pod "pod-subpath-test-dynamicpv-bfw8" satisfied condition "Succeeded or Failed"
Sep  6 00:53:52.852: INFO: Trying to get logs from node k3s-master pod pod-subpath-test-dynamicpv-bfw8 container test-container-subpath-dynamicpv-bfw8: <nil>
STEP: delete the pod
Sep  6 00:53:52.878: INFO: Waiting for pod pod-subpath-test-dynamicpv-bfw8 to disappear
Sep  6 00:53:52.883: INFO: Pod pod-subpath-test-dynamicpv-bfw8 no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-bfw8
Sep  6 00:53:52.883: INFO: Deleting pod "pod-subpath-test-dynamicpv-bfw8" in namespace "provisioning-7402"
... skipping 16 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should support readOnly directory specified in the volumeMount
    test/e2e/storage/testsuites/subpath.go:367
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath should support readOnly directory specified in the volumeMount","total":244,"completed":13,"skipped":1365,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath 
  should support restarting containers using directory as subpath [Slow]
  test/e2e/storage/testsuites/subpath.go:322
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
... skipping 305 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (block volmode)(allowExpansion)] volume-expand
  test/e2e/storage/framework/testsuite.go:50
    should resize volume when PVC is edited while pod is using it
    test/e2e/storage/testsuites/volume_expand.go:248
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (block volmode)(allowExpansion)] volume-expand should resize volume when PVC is edited while pod is using it","total":244,"completed":14,"skipped":1823,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (default fs)] subPath 
  should be able to unmount after the subpath directory is deleted [LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:447
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
... skipping 123 lines ...

    test/e2e/storage/external/external.go:262
------------------------------
SS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Inline-volume (default fs)] subPath 
  should fail if subpath file is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:258
[BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
Sep  6 00:55:53.410: INFO: Driver "cinder.csi.openstack.org" does not support volume type "InlineVolume" - skipping
[AfterEach] [Testpattern: Inline-volume (default fs)] subPath
  test/e2e/framework/framework.go:188

S [SKIPPING] in Spec Setup (BeforeEach) [0.000 seconds]
External Storage [Driver: cinder.csi.openstack.org]
test/e2e/storage/external/external.go:174
  [Testpattern: Inline-volume (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath file is outside the volume [Slow][LinuxOnly] [BeforeEach]
    test/e2e/storage/testsuites/subpath.go:258

    Driver "cinder.csi.openstack.org" does not support volume type "InlineVolume" - skipping

    test/e2e/storage/external/external.go:262
------------------------------
... skipping 20 lines ...
Sep  6 00:55:53.440: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  6 00:55:53.460: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.org76vxs] to have phase Bound
Sep  6 00:55:53.463: INFO: PersistentVolumeClaim cinder.csi.openstack.org76vxs found but phase is Pending instead of Bound.
Sep  6 00:55:55.469: INFO: PersistentVolumeClaim cinder.csi.openstack.org76vxs found and phase=Bound (2.008521167s)
STEP: Creating pod pod-subpath-test-dynamicpv-z2hn
STEP: Creating a pod to test subpath
Sep  6 00:55:55.490: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-z2hn" in namespace "provisioning-5844" to be "Succeeded or Failed"
Sep  6 00:55:55.493: INFO: Pod "pod-subpath-test-dynamicpv-z2hn": Phase="Pending", Reason="", readiness=false. Elapsed: 2.95597ms
Sep  6 00:55:57.498: INFO: Pod "pod-subpath-test-dynamicpv-z2hn": Phase="Pending", Reason="", readiness=false. Elapsed: 2.007607092s
Sep  6 00:55:59.503: INFO: Pod "pod-subpath-test-dynamicpv-z2hn": Phase="Pending", Reason="", readiness=false. Elapsed: 4.012365049s
Sep  6 00:56:01.510: INFO: Pod "pod-subpath-test-dynamicpv-z2hn": Phase="Pending", Reason="", readiness=false. Elapsed: 6.020001099s
Sep  6 00:56:03.516: INFO: Pod "pod-subpath-test-dynamicpv-z2hn": Phase="Pending", Reason="", readiness=false. Elapsed: 8.025210084s
Sep  6 00:56:05.524: INFO: Pod "pod-subpath-test-dynamicpv-z2hn": Phase="Pending", Reason="", readiness=false. Elapsed: 10.033049479s
Sep  6 00:56:07.529: INFO: Pod "pod-subpath-test-dynamicpv-z2hn": Phase="Pending", Reason="", readiness=false. Elapsed: 12.03812222s
Sep  6 00:56:09.534: INFO: Pod "pod-subpath-test-dynamicpv-z2hn": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.043123117s
STEP: Saw pod success
Sep  6 00:56:09.534: INFO: Pod "pod-subpath-test-dynamicpv-z2hn" satisfied condition "Succeeded or Failed"
Sep  6 00:56:09.537: INFO: Trying to get logs from node k3s-master pod pod-subpath-test-dynamicpv-z2hn container test-container-subpath-dynamicpv-z2hn: <nil>
STEP: delete the pod
Sep  6 00:56:09.557: INFO: Waiting for pod pod-subpath-test-dynamicpv-z2hn to disappear
Sep  6 00:56:09.562: INFO: Pod pod-subpath-test-dynamicpv-z2hn no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-z2hn
Sep  6 00:56:09.562: INFO: Deleting pod "pod-subpath-test-dynamicpv-z2hn" in namespace "provisioning-5844"
... skipping 15 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should support existing single file [LinuxOnly]
    test/e2e/storage/testsuites/subpath.go:221
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath should support existing single file [LinuxOnly]","total":244,"completed":15,"skipped":1976,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (ext4)] volumes 
  should store data
  test/e2e/storage/testsuites/volumes.go:161
[BeforeEach] [Testpattern: Pre-provisioned PV (ext4)] volumes
... skipping 60 lines ...
Sep  6 00:56:14.696: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  6 00:56:14.714: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.org7vcnx] to have phase Bound
Sep  6 00:56:14.718: INFO: PersistentVolumeClaim cinder.csi.openstack.org7vcnx found but phase is Pending instead of Bound.
Sep  6 00:56:16.726: INFO: PersistentVolumeClaim cinder.csi.openstack.org7vcnx found and phase=Bound (2.012398351s)
STEP: Creating pod exec-volume-test-dynamicpv-bskp
STEP: Creating a pod to test exec-volume-test
Sep  6 00:56:16.739: INFO: Waiting up to 5m0s for pod "exec-volume-test-dynamicpv-bskp" in namespace "volume-5398" to be "Succeeded or Failed"
Sep  6 00:56:16.742: INFO: Pod "exec-volume-test-dynamicpv-bskp": Phase="Pending", Reason="", readiness=false. Elapsed: 3.074389ms
Sep  6 00:56:18.747: INFO: Pod "exec-volume-test-dynamicpv-bskp": Phase="Pending", Reason="", readiness=false. Elapsed: 2.008154707s
Sep  6 00:56:20.753: INFO: Pod "exec-volume-test-dynamicpv-bskp": Phase="Pending", Reason="", readiness=false. Elapsed: 4.014336298s
Sep  6 00:56:22.759: INFO: Pod "exec-volume-test-dynamicpv-bskp": Phase="Pending", Reason="", readiness=false. Elapsed: 6.019959886s
Sep  6 00:56:24.763: INFO: Pod "exec-volume-test-dynamicpv-bskp": Phase="Pending", Reason="", readiness=false. Elapsed: 8.024305698s
Sep  6 00:56:26.769: INFO: Pod "exec-volume-test-dynamicpv-bskp": Phase="Pending", Reason="", readiness=false. Elapsed: 10.029551948s
Sep  6 00:56:28.773: INFO: Pod "exec-volume-test-dynamicpv-bskp": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.033850013s
STEP: Saw pod success
Sep  6 00:56:28.773: INFO: Pod "exec-volume-test-dynamicpv-bskp" satisfied condition "Succeeded or Failed"
Sep  6 00:56:28.776: INFO: Trying to get logs from node k3s-master pod exec-volume-test-dynamicpv-bskp container exec-container-dynamicpv-bskp: <nil>
STEP: delete the pod
Sep  6 00:56:28.794: INFO: Waiting for pod exec-volume-test-dynamicpv-bskp to disappear
Sep  6 00:56:28.800: INFO: Pod exec-volume-test-dynamicpv-bskp no longer exists
STEP: Deleting pod exec-volume-test-dynamicpv-bskp
Sep  6 00:56:28.800: INFO: Deleting pod "exec-volume-test-dynamicpv-bskp" in namespace "volume-5398"
... skipping 14 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (xfs)][Slow] volumes
  test/e2e/storage/framework/testsuite.go:50
    should allow exec of files on the volume
    test/e2e/storage/testsuites/volumes.go:198
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (xfs)][Slow] volumes should allow exec of files on the volume","total":244,"completed":16,"skipped":2103,"failed":0}
SSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic Snapshot (delete policy)] snapshottable-stress[Feature:VolumeSnapshotDataSource] 
  should support snapshotting of many volumes repeatedly [Slow] [Serial]
  test/e2e/storage/testsuites/snapshottable_stress.go:259
[BeforeEach] [Testpattern: Dynamic Snapshot (delete policy)] snapshottable-stress[Feature:VolumeSnapshotDataSource]
... skipping 200 lines ...

    test/e2e/storage/external/external.go:262
------------------------------
SSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath 
  should fail if non-existent subpath is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:269
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/framework/framework.go:187
STEP: Creating a kubernetes client
Sep  6 00:56:39.010: INFO: >>> kubeConfig: /root/.kube/config
STEP: Building a namespace api object, basename provisioning
STEP: Waiting for a default service account to be provisioned in namespace
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
[It] should fail if non-existent subpath is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:269
Sep  6 00:56:39.040: INFO: Creating resource for dynamic PV
Sep  6 00:56:39.040: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(cinder.csi.openstack.org) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-8696-e2e-scz7hgs
STEP: creating a claim
Sep  6 00:56:39.048: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  6 00:56:39.058: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgjqqgf] to have phase Bound
Sep  6 00:56:39.064: INFO: PersistentVolumeClaim cinder.csi.openstack.orgjqqgf found but phase is Pending instead of Bound.
Sep  6 00:56:41.072: INFO: PersistentVolumeClaim cinder.csi.openstack.orgjqqgf found and phase=Bound (2.013971235s)
STEP: Creating pod pod-subpath-test-dynamicpv-5hcc
STEP: Checking for subpath error in container status
Sep  6 00:56:55.097: INFO: Deleting pod "pod-subpath-test-dynamicpv-5hcc" in namespace "provisioning-8696"
Sep  6 00:56:55.112: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-5hcc" to be fully deleted
STEP: Deleting pod
Sep  6 00:56:57.120: INFO: Deleting pod "pod-subpath-test-dynamicpv-5hcc" in namespace "provisioning-8696"
STEP: Deleting pvc
Sep  6 00:56:57.124: INFO: Deleting PersistentVolumeClaim "cinder.csi.openstack.orgjqqgf"
... skipping 9 lines ...

• [SLOW TEST:28.159 seconds]
External Storage [Driver: cinder.csi.openstack.org]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if non-existent subpath is outside the volume [Slow][LinuxOnly]
    test/e2e/storage/testsuites/subpath.go:269
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath should fail if non-existent subpath is outside the volume [Slow][LinuxOnly]","total":244,"completed":17,"skipped":2290,"failed":0}
SSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Inline-volume (default fs)] subPath 
  should support readOnly file specified in the volumeMount [LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:382
[BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
... skipping 172 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy
  test/e2e/storage/framework/testsuite.go:50
    (Always)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed via chgrp in first pod, new pod with same fsgroup applied to the volume contents
    test/e2e/storage/testsuites/fsgroupchangepolicy.go:216
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (Always)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed via chgrp in first pod, new pod with same fsgroup applied to the volume contents","total":244,"completed":18,"skipped":2390,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Inline-volume (default fs)] volumeIO 
  should write files of various sizes, verify size, validate content [Slow]
  test/e2e/storage/testsuites/volume_io.go:149
[BeforeEach] [Testpattern: Inline-volume (default fs)] volumeIO
... skipping 308 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (block volmode)] provisioning
  test/e2e/storage/framework/testsuite.go:50
    should provision storage with pvc data source in parallel [Slow]
    test/e2e/storage/testsuites/provisioning.go:459
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (block volmode)] provisioning should provision storage with pvc data source in parallel [Slow]","total":244,"completed":19,"skipped":2448,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Ephemeral Snapshot (retain policy)] snapshottable[Feature:VolumeSnapshotDataSource] volume snapshot controller  
  should check snapshot fields, check restore correctly works, check deletion (ephemeral)
  test/e2e/storage/testsuites/snapshottable.go:177
[BeforeEach] [Testpattern: Ephemeral Snapshot (retain policy)] snapshottable[Feature:VolumeSnapshotDataSource]
... skipping 8 lines ...
[It] should check snapshot fields, check restore correctly works, check deletion (ephemeral)
  test/e2e/storage/testsuites/snapshottable.go:177
Sep  6 00:59:32.107: INFO: Creating resource for dynamic PV
Sep  6 00:59:32.107: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(cinder.csi.openstack.org) supported size:{ 1Mi} 
STEP: creating a StorageClass snapshotting-1266-e2e-sc989jr
STEP: [init] starting a pod to use the claim
Sep  6 00:59:32.144: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-2hlxc" in namespace "snapshotting-1266" to be "Succeeded or Failed"
Sep  6 00:59:32.148: INFO: Pod "pvc-snapshottable-tester-2hlxc": Phase="Pending", Reason="", readiness=false. Elapsed: 4.231819ms
Sep  6 00:59:34.152: INFO: Pod "pvc-snapshottable-tester-2hlxc": Phase="Pending", Reason="", readiness=false. Elapsed: 2.008412782s
Sep  6 00:59:36.159: INFO: Pod "pvc-snapshottable-tester-2hlxc": Phase="Pending", Reason="", readiness=false. Elapsed: 4.014827539s
Sep  6 00:59:38.163: INFO: Pod "pvc-snapshottable-tester-2hlxc": Phase="Pending", Reason="", readiness=false. Elapsed: 6.019246202s
Sep  6 00:59:40.169: INFO: Pod "pvc-snapshottable-tester-2hlxc": Phase="Pending", Reason="", readiness=false. Elapsed: 8.025214929s
Sep  6 00:59:42.173: INFO: Pod "pvc-snapshottable-tester-2hlxc": Phase="Pending", Reason="", readiness=false. Elapsed: 10.029497475s
Sep  6 00:59:44.179: INFO: Pod "pvc-snapshottable-tester-2hlxc": Phase="Pending", Reason="", readiness=false. Elapsed: 12.035090785s
Sep  6 00:59:46.185: INFO: Pod "pvc-snapshottable-tester-2hlxc": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.040616893s
STEP: Saw pod success
Sep  6 00:59:46.185: INFO: Pod "pvc-snapshottable-tester-2hlxc" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
STEP: creating a SnapshotClass
STEP: creating a dynamic VolumeSnapshot
Sep  6 00:59:46.235: INFO: Waiting up to 5m0s for VolumeSnapshot snapshot-5xjgb to become ready
Sep  6 00:59:46.257: INFO: VolumeSnapshot snapshot-5xjgb found but is not ready.
Sep  6 00:59:48.262: INFO: VolumeSnapshot snapshot-5xjgb found but is not ready.
... skipping 106 lines ...
Sep  6 01:02:34.875: INFO: volumesnapshotcontents snapcontent-d16919f6-2512-4dad-8988-4bceb6b299be has been found and is not deleted
Sep  6 01:02:35.880: INFO: volumesnapshotcontents snapcontent-d16919f6-2512-4dad-8988-4bceb6b299be has been found and is not deleted
Sep  6 01:02:36.885: INFO: volumesnapshotcontents snapcontent-d16919f6-2512-4dad-8988-4bceb6b299be has been found and is not deleted
Sep  6 01:02:37.890: INFO: volumesnapshotcontents snapcontent-d16919f6-2512-4dad-8988-4bceb6b299be has been found and is not deleted
Sep  6 01:02:38.895: INFO: volumesnapshotcontents snapcontent-d16919f6-2512-4dad-8988-4bceb6b299be has been found and is not deleted
Sep  6 01:02:39.901: INFO: volumesnapshotcontents snapcontent-d16919f6-2512-4dad-8988-4bceb6b299be has been found and is not deleted
Sep  6 01:02:40.901: INFO: WaitUntil failed after reaching the timeout 30s
[AfterEach] volume snapshot controller
  test/e2e/storage/testsuites/snapshottable.go:172
Sep  6 01:02:40.919: INFO: Pod restored-pvc-tester-48hpr has the following logs: 
Sep  6 01:02:40.919: INFO: Deleting pod "restored-pvc-tester-48hpr" in namespace "snapshotting-1266"
Sep  6 01:02:40.939: INFO: Wait up to 5m0s for pod "restored-pvc-tester-48hpr" to be fully deleted
Sep  6 01:03:12.986: INFO: deleting snapshot "snapshotting-1266"/"snapshot-5xjgb"
... skipping 23 lines ...
    test/e2e/storage/testsuites/snapshottable.go:113
      
      test/e2e/storage/testsuites/snapshottable.go:176
        should check snapshot fields, check restore correctly works, check deletion (ephemeral)
        test/e2e/storage/testsuites/snapshottable.go:177
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Ephemeral Snapshot (retain policy)] snapshottable[Feature:VolumeSnapshotDataSource] volume snapshot controller  should check snapshot fields, check restore correctly works, check deletion (ephemeral)","total":244,"completed":20,"skipped":2550,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow] 
  should concurrently access the volume and restored snapshot from pods on the same node [LinuxOnly][Feature:VolumeSnapshotDataSource][Feature:VolumeSourceXFS]
  test/e2e/storage/testsuites/multivolume.go:323
[BeforeEach] [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow]
... skipping 99 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should concurrently access the volume and restored snapshot from pods on the same node [LinuxOnly][Feature:VolumeSnapshotDataSource][Feature:VolumeSourceXFS]
    test/e2e/storage/testsuites/multivolume.go:323
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow] should concurrently access the volume and restored snapshot from pods on the same node [LinuxOnly][Feature:VolumeSnapshotDataSource][Feature:VolumeSourceXFS]","total":244,"completed":21,"skipped":2601,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] 
  should concurrently access the single read-only volume from pods on the same node
  test/e2e/storage/testsuites/multivolume.go:423
[BeforeEach] [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow]
... skipping 73 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should concurrently access the single read-only volume from pods on the same node
    test/e2e/storage/testsuites/multivolume.go:423
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] should concurrently access the single read-only volume from pods on the same node","total":244,"completed":22,"skipped":2672,"failed":0}
S
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (xfs)][Slow] volumes 
  should store data
  test/e2e/storage/testsuites/volumes.go:161
[BeforeEach] [Testpattern: Dynamic PV (xfs)][Slow] volumes
... skipping 99 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (xfs)][Slow] volumes
  test/e2e/storage/framework/testsuite.go:50
    should store data
    test/e2e/storage/testsuites/volumes.go:161
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (xfs)][Slow] volumes should store data","total":244,"completed":23,"skipped":2673,"failed":0}
SSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] provisioning 
  should provision storage with pvc data source in parallel [Slow]
  test/e2e/storage/testsuites/provisioning.go:459
[BeforeEach] [Testpattern: Dynamic PV (default fs)] provisioning
... skipping 286 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] provisioning
  test/e2e/storage/framework/testsuite.go:50
    should provision storage with pvc data source in parallel [Slow]
    test/e2e/storage/testsuites/provisioning.go:459
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] provisioning should provision storage with pvc data source in parallel [Slow]","total":244,"completed":24,"skipped":2688,"failed":0}
SSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (immediate binding)] topology 
  should fail to schedule a pod which has topologies that conflict with AllowedTopologies
  test/e2e/storage/testsuites/topology.go:194
[BeforeEach] [Testpattern: Dynamic PV (immediate binding)] topology
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (immediate binding)] topology
  test/e2e/framework/framework.go:187
STEP: Creating a kubernetes client
Sep  6 01:07:29.431: INFO: >>> kubeConfig: /root/.kube/config
STEP: Building a namespace api object, basename topology
STEP: Waiting for a default service account to be provisioned in namespace
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
[It] should fail to schedule a pod which has topologies that conflict with AllowedTopologies
  test/e2e/storage/testsuites/topology.go:194
Sep  6 01:07:29.485: INFO: found topology map[topology.cinder.csi.openstack.org/zone:nova]
Sep  6 01:07:29.485: INFO: Not enough topologies in cluster -- skipping
STEP: Deleting pvc
STEP: Deleting sc
[AfterEach] [Testpattern: Dynamic PV (immediate binding)] topology
... skipping 3 lines ...

S [SKIPPING] [0.072 seconds]
External Storage [Driver: cinder.csi.openstack.org]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (immediate binding)] topology
  test/e2e/storage/framework/testsuite.go:50
    should fail to schedule a pod which has topologies that conflict with AllowedTopologies [It]
    test/e2e/storage/testsuites/topology.go:194

    Not enough topologies in cluster -- skipping

    test/e2e/storage/testsuites/topology.go:201
------------------------------
... skipping 184 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should access to two volumes with the same volume mode and retain data across pod recreation on the same node
    test/e2e/storage/testsuites/multivolume.go:138
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow] should access to two volumes with the same volume mode and retain data across pod recreation on the same node","total":244,"completed":25,"skipped":2706,"failed":0}
S
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (block volmode)] multiVolume [Slow] 
  should access to two volumes with the same volume mode and retain data across pod recreation on different node
  test/e2e/storage/testsuites/multivolume.go:168
[BeforeEach] [Testpattern: Pre-provisioned PV (block volmode)] multiVolume [Slow]
... skipping 86 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)(allowExpansion)] volume-expand
  test/e2e/storage/framework/testsuite.go:50
    should resize volume when PVC is edited while pod is using it
    test/e2e/storage/testsuites/volume_expand.go:248
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)(allowExpansion)] volume-expand should resize volume when PVC is edited while pod is using it","total":244,"completed":26,"skipped":2739,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy 
  (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed via chgrp in first pod, new pod with same fsgroup skips ownership changes to the volume contents
  test/e2e/storage/testsuites/fsgroupchangepolicy.go:216
[BeforeEach] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy
... skipping 103 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy
  test/e2e/storage/framework/testsuite.go:50
    (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed via chgrp in first pod, new pod with same fsgroup skips ownership changes to the volume contents
    test/e2e/storage/testsuites/fsgroupchangepolicy.go:216
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed via chgrp in first pod, new pod with same fsgroup skips ownership changes to the volume contents","total":244,"completed":27,"skipped":2858,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned Snapshot (delete policy)] snapshottable[Feature:VolumeSnapshotDataSource] volume snapshot controller  
  should check snapshot fields, check restore correctly works, check deletion (ephemeral)
  test/e2e/storage/testsuites/snapshottable.go:177
[BeforeEach] [Testpattern: Pre-provisioned Snapshot (delete policy)] snapshottable[Feature:VolumeSnapshotDataSource]
... skipping 239 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should access to two volumes with different volume mode and retain data across pod recreation on the same node
    test/e2e/storage/testsuites/multivolume.go:209
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow] should access to two volumes with different volume mode and retain data across pod recreation on the same node","total":244,"completed":28,"skipped":2949,"failed":0}
SSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ntfs)(allowExpansion)][Feature:Windows] volume-expand 
  Verify if offline PVC expansion works
  test/e2e/storage/testsuites/volume_expand.go:176
[BeforeEach] [Testpattern: Dynamic PV (ntfs)(allowExpansion)][Feature:Windows] volume-expand
... skipping 85 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should be able to unmount after the subpath directory is deleted [LinuxOnly]
    test/e2e/storage/testsuites/subpath.go:447
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath should be able to unmount after the subpath directory is deleted [LinuxOnly]","total":244,"completed":29,"skipped":2980,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Generic Ephemeral-volume (block volmode) (late-binding)] ephemeral 
  should create read-only inline ephemeral volume
  test/e2e/storage/testsuites/ephemeral.go:175
[BeforeEach] [Testpattern: Generic Ephemeral-volume (block volmode) (late-binding)] ephemeral
... skipping 135 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should support restarting containers using file as subpath [Slow][LinuxOnly]
    test/e2e/storage/testsuites/subpath.go:333
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath should support restarting containers using file as subpath [Slow][LinuxOnly]","total":244,"completed":30,"skipped":3089,"failed":0}
SSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath 
  should verify container cannot write to subpath readonly volumes [Slow]
  test/e2e/storage/testsuites/subpath.go:425
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
... skipping 70 lines ...
Sep  6 01:14:10.240: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  6 01:14:10.254: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgxl77r] to have phase Bound
Sep  6 01:14:10.272: INFO: PersistentVolumeClaim cinder.csi.openstack.orgxl77r found but phase is Pending instead of Bound.
Sep  6 01:14:12.276: INFO: PersistentVolumeClaim cinder.csi.openstack.orgxl77r found and phase=Bound (2.022238908s)
STEP: [init] starting a pod to use the claim
STEP: [init] check pod success
Sep  6 01:14:12.296: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-rnf5w" in namespace "snapshotting-800" to be "Succeeded or Failed"
Sep  6 01:14:12.299: INFO: Pod "pvc-snapshottable-tester-rnf5w": Phase="Pending", Reason="", readiness=false. Elapsed: 2.886094ms
Sep  6 01:14:14.304: INFO: Pod "pvc-snapshottable-tester-rnf5w": Phase="Pending", Reason="", readiness=false. Elapsed: 2.007814954s
Sep  6 01:14:16.311: INFO: Pod "pvc-snapshottable-tester-rnf5w": Phase="Pending", Reason="", readiness=false. Elapsed: 4.01488171s
Sep  6 01:14:18.316: INFO: Pod "pvc-snapshottable-tester-rnf5w": Phase="Pending", Reason="", readiness=false. Elapsed: 6.020525894s
Sep  6 01:14:20.324: INFO: Pod "pvc-snapshottable-tester-rnf5w": Phase="Pending", Reason="", readiness=false. Elapsed: 8.02765035s
Sep  6 01:14:22.328: INFO: Pod "pvc-snapshottable-tester-rnf5w": Phase="Pending", Reason="", readiness=false. Elapsed: 10.032049767s
Sep  6 01:14:24.333: INFO: Pod "pvc-snapshottable-tester-rnf5w": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.036709322s
STEP: Saw pod success
Sep  6 01:14:24.333: INFO: Pod "pvc-snapshottable-tester-rnf5w" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
Sep  6 01:14:24.336: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgxl77r] to have phase Bound
Sep  6 01:14:24.339: INFO: PersistentVolumeClaim cinder.csi.openstack.orgxl77r found and phase=Bound (2.810338ms)
STEP: [init] checking the PV
STEP: [init] deleting the pod
Sep  6 01:14:24.369: INFO: Pod pvc-snapshottable-tester-rnf5w has the following logs: 
... skipping 17 lines ...
Sep  6 01:14:38.487: INFO: received snapshotStatus map[boundVolumeSnapshotContentName:snapcontent-7737b8d0-de12-46b1-91a2-417bb87ff0ab creationTime:2022-09-06T01:14:35Z readyToUse:true restoreSize:1Gi]
Sep  6 01:14:38.487: INFO: snapshotContentName snapcontent-7737b8d0-de12-46b1-91a2-417bb87ff0ab
STEP: checking the snapshot
STEP: checking the SnapshotContent
STEP: Modifying source data test
STEP: modifying the data in the source PVC
Sep  6 01:14:38.501: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-data-tester-wqtdb" in namespace "snapshotting-800" to be "Succeeded or Failed"
Sep  6 01:14:38.504: INFO: Pod "pvc-snapshottable-data-tester-wqtdb": Phase="Pending", Reason="", readiness=false. Elapsed: 3.007039ms
Sep  6 01:14:40.509: INFO: Pod "pvc-snapshottable-data-tester-wqtdb": Phase="Pending", Reason="", readiness=false. Elapsed: 2.008165007s
Sep  6 01:14:42.520: INFO: Pod "pvc-snapshottable-data-tester-wqtdb": Phase="Pending", Reason="", readiness=false. Elapsed: 4.019313625s
Sep  6 01:14:44.527: INFO: Pod "pvc-snapshottable-data-tester-wqtdb": Phase="Pending", Reason="", readiness=false. Elapsed: 6.026107713s
Sep  6 01:14:46.533: INFO: Pod "pvc-snapshottable-data-tester-wqtdb": Phase="Pending", Reason="", readiness=false. Elapsed: 8.032296605s
Sep  6 01:14:48.539: INFO: Pod "pvc-snapshottable-data-tester-wqtdb": Phase="Running", Reason="", readiness=false. Elapsed: 10.037664317s
Sep  6 01:14:50.543: INFO: Pod "pvc-snapshottable-data-tester-wqtdb": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.04168458s
STEP: Saw pod success
Sep  6 01:14:50.543: INFO: Pod "pvc-snapshottable-data-tester-wqtdb" satisfied condition "Succeeded or Failed"
Sep  6 01:14:50.553: INFO: Pod pvc-snapshottable-data-tester-wqtdb has the following logs: 
Sep  6 01:14:50.553: INFO: Deleting pod "pvc-snapshottable-data-tester-wqtdb" in namespace "snapshotting-800"
Sep  6 01:14:50.563: INFO: Wait up to 5m0s for pod "pvc-snapshottable-data-tester-wqtdb" to be fully deleted
STEP: creating a pvc from the snapshot
STEP: starting a pod to use the snapshot
Sep  6 01:15:00.624: INFO: Running '/usr/local/bin/kubectl --server=https://172.24.5.198:6443 --kubeconfig=/root/.kube/config --namespace=snapshotting-800 exec restored-pvc-tester-5qlv6 --namespace=snapshotting-800 -- cat /mnt/test/data'
... skipping 43 lines ...
    test/e2e/storage/testsuites/snapshottable.go:113
      
      test/e2e/storage/testsuites/snapshottable.go:176
        should check snapshot fields, check restore correctly works after modifying source data, check deletion (persistent)
        test/e2e/storage/testsuites/snapshottable.go:278
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic Snapshot (delete policy)] snapshottable[Feature:VolumeSnapshotDataSource] volume snapshot controller  should check snapshot fields, check restore correctly works after modifying source data, check deletion (persistent)","total":244,"completed":31,"skipped":3125,"failed":0}
SSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] multiVolume [Slow] 
  should access to two volumes with different volume mode and retain data across pod recreation on different node
  test/e2e/storage/testsuites/multivolume.go:248
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] multiVolume [Slow]
... skipping 37 lines ...
Sep  6 01:15:39.985: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  6 01:15:40.018: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgfqgqp] to have phase Bound
Sep  6 01:15:40.035: INFO: PersistentVolumeClaim cinder.csi.openstack.orgfqgqp found but phase is Pending instead of Bound.
Sep  6 01:15:42.040: INFO: PersistentVolumeClaim cinder.csi.openstack.orgfqgqp found and phase=Bound (2.021565851s)
STEP: Creating pod pod-subpath-test-dynamicpv-kklv
STEP: Creating a pod to test multi_subpath
Sep  6 01:15:42.053: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-kklv" in namespace "provisioning-4781" to be "Succeeded or Failed"
Sep  6 01:15:42.060: INFO: Pod "pod-subpath-test-dynamicpv-kklv": Phase="Pending", Reason="", readiness=false. Elapsed: 6.807569ms
Sep  6 01:15:44.069: INFO: Pod "pod-subpath-test-dynamicpv-kklv": Phase="Pending", Reason="", readiness=false. Elapsed: 2.016076497s
Sep  6 01:15:46.075: INFO: Pod "pod-subpath-test-dynamicpv-kklv": Phase="Pending", Reason="", readiness=false. Elapsed: 4.021743843s
Sep  6 01:15:48.080: INFO: Pod "pod-subpath-test-dynamicpv-kklv": Phase="Pending", Reason="", readiness=false. Elapsed: 6.026249859s
Sep  6 01:15:50.084: INFO: Pod "pod-subpath-test-dynamicpv-kklv": Phase="Pending", Reason="", readiness=false. Elapsed: 8.030478265s
Sep  6 01:15:52.088: INFO: Pod "pod-subpath-test-dynamicpv-kklv": Phase="Pending", Reason="", readiness=false. Elapsed: 10.034569561s
Sep  6 01:15:54.095: INFO: Pod "pod-subpath-test-dynamicpv-kklv": Phase="Pending", Reason="", readiness=false. Elapsed: 12.041691717s
Sep  6 01:15:56.100: INFO: Pod "pod-subpath-test-dynamicpv-kklv": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.047109527s
STEP: Saw pod success
Sep  6 01:15:56.100: INFO: Pod "pod-subpath-test-dynamicpv-kklv" satisfied condition "Succeeded or Failed"
Sep  6 01:15:56.104: INFO: Trying to get logs from node k3s-master pod pod-subpath-test-dynamicpv-kklv container test-container-subpath-dynamicpv-kklv: <nil>
STEP: delete the pod
Sep  6 01:15:56.134: INFO: Waiting for pod pod-subpath-test-dynamicpv-kklv to disappear
Sep  6 01:15:56.140: INFO: Pod pod-subpath-test-dynamicpv-kklv no longer exists
STEP: Deleting pod
Sep  6 01:15:56.140: INFO: Deleting pod "pod-subpath-test-dynamicpv-kklv" in namespace "provisioning-4781"
... skipping 13 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should support creating multiple subpath from same volumes [Slow]
    test/e2e/storage/testsuites/subpath.go:296
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath should support creating multiple subpath from same volumes [Slow]","total":244,"completed":32,"skipped":3138,"failed":0}
SSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Ephemeral Snapshot (delete policy)] snapshottable[Feature:VolumeSnapshotDataSource] volume snapshot controller  
  should check snapshot fields, check restore correctly works after modifying source data, check deletion (persistent)
  test/e2e/storage/testsuites/snapshottable.go:278
[BeforeEach] [Testpattern: Ephemeral Snapshot (delete policy)] snapshottable[Feature:VolumeSnapshotDataSource]
... skipping 31 lines ...

        test/e2e/storage/testsuites/snapshottable.go:280
------------------------------
SS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath 
  should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:280
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/framework/framework.go:187
STEP: Creating a kubernetes client
Sep  6 01:16:01.243: INFO: >>> kubeConfig: /root/.kube/config
STEP: Building a namespace api object, basename provisioning
STEP: Waiting for a default service account to be provisioned in namespace
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
[It] should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:280
Sep  6 01:16:01.271: INFO: Creating resource for dynamic PV
Sep  6 01:16:01.271: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(cinder.csi.openstack.org) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-1022-e2e-sc79k86
STEP: creating a claim
Sep  6 01:16:01.278: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  6 01:16:01.292: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgsq6xp] to have phase Bound
Sep  6 01:16:01.299: INFO: PersistentVolumeClaim cinder.csi.openstack.orgsq6xp found but phase is Pending instead of Bound.
Sep  6 01:16:03.303: INFO: PersistentVolumeClaim cinder.csi.openstack.orgsq6xp found and phase=Bound (2.011502752s)
STEP: Creating pod pod-subpath-test-dynamicpv-8gtx
STEP: Checking for subpath error in container status
Sep  6 01:16:13.333: INFO: Deleting pod "pod-subpath-test-dynamicpv-8gtx" in namespace "provisioning-1022"
Sep  6 01:16:13.344: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-8gtx" to be fully deleted
STEP: Deleting pod
Sep  6 01:16:15.365: INFO: Deleting pod "pod-subpath-test-dynamicpv-8gtx" in namespace "provisioning-1022"
STEP: Deleting pvc
Sep  6 01:16:15.369: INFO: Deleting PersistentVolumeClaim "cinder.csi.openstack.orgsq6xp"
... skipping 8 lines ...

• [SLOW TEST:19.167 seconds]
External Storage [Driver: cinder.csi.openstack.org]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly]
    test/e2e/storage/testsuites/subpath.go:280
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly]","total":244,"completed":33,"skipped":3147,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Generic Ephemeral-volume (default fs)] volumeLimits 
  should support volume limits [Serial]
  test/e2e/storage/testsuites/volumelimits.go:127
[BeforeEach] [Testpattern: Generic Ephemeral-volume (default fs)] volumeLimits
... skipping 105 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should concurrently access the volume and its clone from pods on the same node [LinuxOnly][Feature:VolumeSnapshotDataSource][Feature:VolumeSourceXFS]
    test/e2e/storage/testsuites/multivolume.go:378
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] should concurrently access the volume and its clone from pods on the same node [LinuxOnly][Feature:VolumeSnapshotDataSource][Feature:VolumeSourceXFS]","total":244,"completed":34,"skipped":3255,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ext4)] multiVolume [Slow] 
  should concurrently access the single read-only volume from pods on the same node
  test/e2e/storage/testsuites/multivolume.go:423
[BeforeEach] [Testpattern: Dynamic PV (ext4)] multiVolume [Slow]
... skipping 74 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (ext4)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should concurrently access the single read-only volume from pods on the same node
    test/e2e/storage/testsuites/multivolume.go:423
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ext4)] multiVolume [Slow] should concurrently access the single read-only volume from pods on the same node","total":244,"completed":35,"skipped":3313,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral 
  should support two pods which have the same volume definition
  test/e2e/storage/testsuites/ephemeral.go:216
[BeforeEach] [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral
... skipping 51 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral
  test/e2e/storage/framework/testsuite.go:50
    should support two pods which have the same volume definition
    test/e2e/storage/testsuites/ephemeral.go:216
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral should support two pods which have the same volume definition","total":244,"completed":36,"skipped":3346,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow] 
  should access to two volumes with the same volume mode and retain data across pod recreation on the same node
  test/e2e/storage/testsuites/multivolume.go:138
[BeforeEach] [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow]
... skipping 180 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should access to two volumes with the same volume mode and retain data across pod recreation on the same node
    test/e2e/storage/testsuites/multivolume.go:138
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow] should access to two volumes with the same volume mode and retain data across pod recreation on the same node","total":244,"completed":37,"skipped":3387,"failed":0}
SS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (default fs)] subPath 
  should support readOnly directory specified in the volumeMount
  test/e2e/storage/testsuites/subpath.go:367
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
... skipping 96 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (ext4)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should concurrently access the volume and its clone from pods on the same node [LinuxOnly][Feature:VolumeSnapshotDataSource][Feature:VolumeSourceXFS]
    test/e2e/storage/testsuites/multivolume.go:378
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ext4)] multiVolume [Slow] should concurrently access the volume and its clone from pods on the same node [LinuxOnly][Feature:VolumeSnapshotDataSource][Feature:VolumeSourceXFS]","total":244,"completed":38,"skipped":3426,"failed":0}
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] capacity 
  provides storage capacity information
  test/e2e/storage/testsuites/capacity.go:112
[BeforeEach] [Testpattern: Dynamic PV (default fs)] capacity
  test/e2e/storage/framework/testsuite.go:51
Sep  6 01:21:59.934: INFO: Driver cinder.csi.openstack.org doesn't publish storage capacity -- skipping
... skipping 187 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should concurrently access the single volume from pods on the same node
    test/e2e/storage/testsuites/multivolume.go:298
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow] should concurrently access the single volume from pods on the same node","total":244,"completed":39,"skipped":3460,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Inline-volume (default fs)] subPath 
  should support restarting containers using directory as subpath [Slow]
  test/e2e/storage/testsuites/subpath.go:322
[BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
... skipping 127 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy
  test/e2e/storage/framework/testsuite.go:50
    (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, new pod fsgroup applied to volume contents
    test/e2e/storage/testsuites/fsgroupchangepolicy.go:216
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, new pod fsgroup applied to volume contents","total":244,"completed":40,"skipped":3549,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (filesystem volmode)] multiVolume [Slow] 
  should access to two volumes with the same volume mode and retain data across pod recreation on the same node
  test/e2e/storage/testsuites/multivolume.go:138
[BeforeEach] [Testpattern: Pre-provisioned PV (filesystem volmode)] multiVolume [Slow]
... skipping 175 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should concurrently access the volume and its clone from pods on the same node [LinuxOnly][Feature:VolumeSnapshotDataSource][Feature:VolumeSourceXFS]
    test/e2e/storage/testsuites/multivolume.go:378
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow] should concurrently access the volume and its clone from pods on the same node [LinuxOnly][Feature:VolumeSnapshotDataSource][Feature:VolumeSourceXFS]","total":244,"completed":41,"skipped":3617,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)(allowExpansion)] volume-expand 
  Verify if offline PVC expansion works
  test/e2e/storage/testsuites/volume_expand.go:176
[BeforeEach] [Testpattern: Dynamic PV (default fs)(allowExpansion)] volume-expand
... skipping 49 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)(allowExpansion)] volume-expand
  test/e2e/storage/framework/testsuite.go:50
    Verify if offline PVC expansion works
    test/e2e/storage/testsuites/volume_expand.go:176
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)(allowExpansion)] volume-expand Verify if offline PVC expansion works","total":244,"completed":42,"skipped":3657,"failed":0}
SSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Inline-volume (default fs)] subPath 
  should support restarting containers using file as subpath [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:333
[BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
... skipping 115 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (delayed binding)] topology
  test/e2e/storage/framework/testsuite.go:50
    should provision a volume and schedule a pod with AllowedTopologies
    test/e2e/storage/testsuites/topology.go:166
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (delayed binding)] topology should provision a volume and schedule a pod with AllowedTopologies","total":244,"completed":43,"skipped":3760,"failed":0}
SSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath 
  should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:280
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  test/e2e/storage/framework/testsuite.go:51
Sep  6 01:25:27.551: INFO: Driver cinder.csi.openstack.org doesn't support ntfs -- skipping
[AfterEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  test/e2e/framework/framework.go:188

S [SKIPPING] in Spec Setup (BeforeEach) [0.000 seconds]
External Storage [Driver: cinder.csi.openstack.org]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly] [BeforeEach]
    test/e2e/storage/testsuites/subpath.go:280

    Driver cinder.csi.openstack.org doesn't support ntfs -- skipping

    test/e2e/storage/framework/testsuite.go:121
------------------------------
... skipping 20 lines ...
Sep  6 01:25:27.602: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  6 01:25:27.616: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgfvgd6] to have phase Bound
Sep  6 01:25:27.619: INFO: PersistentVolumeClaim cinder.csi.openstack.orgfvgd6 found but phase is Pending instead of Bound.
Sep  6 01:25:29.626: INFO: PersistentVolumeClaim cinder.csi.openstack.orgfvgd6 found and phase=Bound (2.010234692s)
STEP: Creating pod exec-volume-test-dynamicpv-88hl
STEP: Creating a pod to test exec-volume-test
Sep  6 01:25:29.646: INFO: Waiting up to 5m0s for pod "exec-volume-test-dynamicpv-88hl" in namespace "volume-2946" to be "Succeeded or Failed"
Sep  6 01:25:29.653: INFO: Pod "exec-volume-test-dynamicpv-88hl": Phase="Pending", Reason="", readiness=false. Elapsed: 7.245153ms
Sep  6 01:25:31.659: INFO: Pod "exec-volume-test-dynamicpv-88hl": Phase="Pending", Reason="", readiness=false. Elapsed: 2.013557567s
Sep  6 01:25:33.670: INFO: Pod "exec-volume-test-dynamicpv-88hl": Phase="Pending", Reason="", readiness=false. Elapsed: 4.024694743s
Sep  6 01:25:35.675: INFO: Pod "exec-volume-test-dynamicpv-88hl": Phase="Pending", Reason="", readiness=false. Elapsed: 6.029754061s
Sep  6 01:25:37.683: INFO: Pod "exec-volume-test-dynamicpv-88hl": Phase="Pending", Reason="", readiness=false. Elapsed: 8.037662199s
Sep  6 01:25:39.690: INFO: Pod "exec-volume-test-dynamicpv-88hl": Phase="Pending", Reason="", readiness=false. Elapsed: 10.043966666s
Sep  6 01:25:41.697: INFO: Pod "exec-volume-test-dynamicpv-88hl": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.051639652s
STEP: Saw pod success
Sep  6 01:25:41.697: INFO: Pod "exec-volume-test-dynamicpv-88hl" satisfied condition "Succeeded or Failed"
Sep  6 01:25:41.703: INFO: Trying to get logs from node k3s-master pod exec-volume-test-dynamicpv-88hl container exec-container-dynamicpv-88hl: <nil>
STEP: delete the pod
Sep  6 01:25:41.734: INFO: Waiting for pod exec-volume-test-dynamicpv-88hl to disappear
Sep  6 01:25:41.749: INFO: Pod exec-volume-test-dynamicpv-88hl no longer exists
STEP: Deleting pod exec-volume-test-dynamicpv-88hl
Sep  6 01:25:41.749: INFO: Deleting pod "exec-volume-test-dynamicpv-88hl" in namespace "volume-2946"
... skipping 16 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (ext3)] volumes
  test/e2e/storage/framework/testsuite.go:50
    should allow exec of files on the volume
    test/e2e/storage/testsuites/volumes.go:198
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ext3)] volumes should allow exec of files on the volume","total":244,"completed":44,"skipped":3772,"failed":0}
S
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (filesystem volmode)] multiVolume [Slow] 
  should access to two volumes with different volume mode and retain data across pod recreation on the same node
  test/e2e/storage/testsuites/multivolume.go:209
[BeforeEach] [Testpattern: Pre-provisioned PV (filesystem volmode)] multiVolume [Slow]
... skipping 138 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] provisioning
  test/e2e/storage/framework/testsuite.go:50
    should provision storage with snapshot data source [Feature:VolumeSnapshotDataSource]
    test/e2e/storage/testsuites/provisioning.go:208
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] provisioning should provision storage with snapshot data source [Feature:VolumeSnapshotDataSource]","total":244,"completed":45,"skipped":3795,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Inline-volume (default fs)] subPath 
  should support existing directory
  test/e2e/storage/testsuites/subpath.go:207
[BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
... skipping 61 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Generic Ephemeral-volume (block volmode) (late-binding)] ephemeral
  test/e2e/storage/framework/testsuite.go:50
    should create read/write inline ephemeral volume
    test/e2e/storage/testsuites/ephemeral.go:196
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Generic Ephemeral-volume (block volmode) (late-binding)] ephemeral should create read/write inline ephemeral volume","total":244,"completed":46,"skipped":3878,"failed":0}
SSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (filesystem volmode)] multiVolume [Slow] 
  should concurrently access the volume and restored snapshot from pods on the same node [LinuxOnly][Feature:VolumeSnapshotDataSource][Feature:VolumeSourceXFS]
  test/e2e/storage/testsuites/multivolume.go:323
[BeforeEach] [Testpattern: Pre-provisioned PV (filesystem volmode)] multiVolume [Slow]
... skipping 97 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should concurrently access the single read-only volume from pods on the same node
    test/e2e/storage/testsuites/multivolume.go:423
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow] should concurrently access the single read-only volume from pods on the same node","total":244,"completed":47,"skipped":3942,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (filesystem volmode)] volume-lifecycle-performance 
  should provision volumes at scale within performance constraints [Slow] [Serial]
  test/e2e/storage/testsuites/volumeperf.go:147
[BeforeEach] [Testpattern: Dynamic PV (filesystem volmode)] volume-lifecycle-performance
... skipping 118 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (block volmode)] provisioning
  test/e2e/storage/framework/testsuite.go:50
    should provision storage with pvc data source
    test/e2e/storage/testsuites/provisioning.go:421
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (block volmode)] provisioning should provision storage with pvc data source","total":244,"completed":48,"skipped":3976,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: CSI Ephemeral-volume (default fs)] ephemeral 
  should create read/write inline ephemeral volume
  test/e2e/storage/testsuites/ephemeral.go:196
[BeforeEach] [Testpattern: CSI Ephemeral-volume (default fs)] ephemeral
... skipping 36 lines ...
STEP: creating a claim
Sep  6 01:29:42.683: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  6 01:29:42.717: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgz62lj] to have phase Bound
Sep  6 01:29:42.741: INFO: PersistentVolumeClaim cinder.csi.openstack.orgz62lj found but phase is Pending instead of Bound.
Sep  6 01:29:44.746: INFO: PersistentVolumeClaim cinder.csi.openstack.orgz62lj found and phase=Bound (2.029090042s)
STEP: Creating pod to format volume volume-prep-provisioning-5543
Sep  6 01:29:44.760: INFO: Waiting up to 5m0s for pod "volume-prep-provisioning-5543" in namespace "provisioning-5543" to be "Succeeded or Failed"
Sep  6 01:29:44.766: INFO: Pod "volume-prep-provisioning-5543": Phase="Pending", Reason="", readiness=false. Elapsed: 6.441619ms
Sep  6 01:29:46.771: INFO: Pod "volume-prep-provisioning-5543": Phase="Pending", Reason="", readiness=false. Elapsed: 2.011867512s
Sep  6 01:29:48.776: INFO: Pod "volume-prep-provisioning-5543": Phase="Pending", Reason="", readiness=false. Elapsed: 4.016831191s
Sep  6 01:29:50.782: INFO: Pod "volume-prep-provisioning-5543": Phase="Pending", Reason="", readiness=false. Elapsed: 6.022443025s
Sep  6 01:29:52.787: INFO: Pod "volume-prep-provisioning-5543": Phase="Pending", Reason="", readiness=false. Elapsed: 8.027239553s
Sep  6 01:29:54.792: INFO: Pod "volume-prep-provisioning-5543": Phase="Pending", Reason="", readiness=false. Elapsed: 10.032604848s
Sep  6 01:29:56.797: INFO: Pod "volume-prep-provisioning-5543": Phase="Pending", Reason="", readiness=false. Elapsed: 12.03697743s
Sep  6 01:29:58.804: INFO: Pod "volume-prep-provisioning-5543": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.044432811s
STEP: Saw pod success
Sep  6 01:29:58.804: INFO: Pod "volume-prep-provisioning-5543" satisfied condition "Succeeded or Failed"
Sep  6 01:29:58.804: INFO: Deleting pod "volume-prep-provisioning-5543" in namespace "provisioning-5543"
Sep  6 01:29:58.821: INFO: Wait up to 5m0s for pod "volume-prep-provisioning-5543" to be fully deleted
STEP: Creating pod pod-subpath-test-dynamicpv-7jls
STEP: Checking for subpath error in container status
Sep  6 01:30:06.846: INFO: Deleting pod "pod-subpath-test-dynamicpv-7jls" in namespace "provisioning-5543"
Sep  6 01:30:06.857: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-7jls" to be fully deleted
STEP: Deleting pod
Sep  6 01:30:08.868: INFO: Deleting pod "pod-subpath-test-dynamicpv-7jls" in namespace "provisioning-5543"
STEP: Deleting pvc
Sep  6 01:30:08.873: INFO: Deleting PersistentVolumeClaim "cinder.csi.openstack.orgz62lj"
... skipping 12 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should verify container cannot write to subpath readonly volumes [Slow]
    test/e2e/storage/testsuites/subpath.go:425
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath should verify container cannot write to subpath readonly volumes [Slow]","total":244,"completed":49,"skipped":4144,"failed":0}
SSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (block volmode)] volume-expand 
  should not allow expansion of pvcs without AllowVolumeExpansion property
  test/e2e/storage/testsuites/volume_expand.go:159
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] volume-expand
... skipping 13 lines ...
STEP: creating a claim
Sep  6 01:30:19.012: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgr7h7x] to have phase Bound
Sep  6 01:30:19.041: INFO: PersistentVolumeClaim cinder.csi.openstack.orgr7h7x found but phase is Pending instead of Bound.
Sep  6 01:30:21.046: INFO: PersistentVolumeClaim cinder.csi.openstack.orgr7h7x found and phase=Bound (2.033529997s)
STEP: Expanding non-expandable pvc
Sep  6 01:30:21.052: INFO: currentPvcSize {{1073741824 0} {<nil>} 1Gi BinarySI}, newSize {{2147483648 0} {<nil>}  BinarySI}
Sep  6 01:30:21.060: INFO: Error updating pvc cinder.csi.openstack.orgr7h7x: persistentvolumeclaims "cinder.csi.openstack.orgr7h7x" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:30:23.070: INFO: Error updating pvc cinder.csi.openstack.orgr7h7x: persistentvolumeclaims "cinder.csi.openstack.orgr7h7x" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:30:25.071: INFO: Error updating pvc cinder.csi.openstack.orgr7h7x: persistentvolumeclaims "cinder.csi.openstack.orgr7h7x" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:30:27.070: INFO: Error updating pvc cinder.csi.openstack.orgr7h7x: persistentvolumeclaims "cinder.csi.openstack.orgr7h7x" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:30:29.072: INFO: Error updating pvc cinder.csi.openstack.orgr7h7x: persistentvolumeclaims "cinder.csi.openstack.orgr7h7x" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:30:31.070: INFO: Error updating pvc cinder.csi.openstack.orgr7h7x: persistentvolumeclaims "cinder.csi.openstack.orgr7h7x" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:30:33.071: INFO: Error updating pvc cinder.csi.openstack.orgr7h7x: persistentvolumeclaims "cinder.csi.openstack.orgr7h7x" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:30:35.080: INFO: Error updating pvc cinder.csi.openstack.orgr7h7x: persistentvolumeclaims "cinder.csi.openstack.orgr7h7x" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:30:37.074: INFO: Error updating pvc cinder.csi.openstack.orgr7h7x: persistentvolumeclaims "cinder.csi.openstack.orgr7h7x" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:30:39.071: INFO: Error updating pvc cinder.csi.openstack.orgr7h7x: persistentvolumeclaims "cinder.csi.openstack.orgr7h7x" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:30:41.073: INFO: Error updating pvc cinder.csi.openstack.orgr7h7x: persistentvolumeclaims "cinder.csi.openstack.orgr7h7x" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:30:43.069: INFO: Error updating pvc cinder.csi.openstack.orgr7h7x: persistentvolumeclaims "cinder.csi.openstack.orgr7h7x" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:30:45.070: INFO: Error updating pvc cinder.csi.openstack.orgr7h7x: persistentvolumeclaims "cinder.csi.openstack.orgr7h7x" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:30:47.073: INFO: Error updating pvc cinder.csi.openstack.orgr7h7x: persistentvolumeclaims "cinder.csi.openstack.orgr7h7x" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:30:49.077: INFO: Error updating pvc cinder.csi.openstack.orgr7h7x: persistentvolumeclaims "cinder.csi.openstack.orgr7h7x" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:30:51.071: INFO: Error updating pvc cinder.csi.openstack.orgr7h7x: persistentvolumeclaims "cinder.csi.openstack.orgr7h7x" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:30:51.077: INFO: Error updating pvc cinder.csi.openstack.orgr7h7x: persistentvolumeclaims "cinder.csi.openstack.orgr7h7x" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
STEP: Deleting pvc
Sep  6 01:30:51.077: INFO: Deleting PersistentVolumeClaim "cinder.csi.openstack.orgr7h7x"
Sep  6 01:30:51.086: INFO: Waiting up to 5m0s for PersistentVolume pvc-bef1e679-c2b1-422d-86fd-dc894cd0a4f7 to get deleted
Sep  6 01:30:51.092: INFO: PersistentVolume pvc-bef1e679-c2b1-422d-86fd-dc894cd0a4f7 found and phase=Bound (5.749584ms)
Sep  6 01:30:56.098: INFO: PersistentVolume pvc-bef1e679-c2b1-422d-86fd-dc894cd0a4f7 was removed
STEP: Deleting sc
... skipping 7 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (block volmode)] volume-expand
  test/e2e/storage/framework/testsuite.go:50
    should not allow expansion of pvcs without AllowVolumeExpansion property
    test/e2e/storage/testsuites/volume_expand.go:159
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (block volmode)] volume-expand should not allow expansion of pvcs without AllowVolumeExpansion property","total":244,"completed":50,"skipped":4157,"failed":0}
SSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Inline-volume (xfs)][Slow] volumes 
  should store data
  test/e2e/storage/testsuites/volumes.go:161
[BeforeEach] [Testpattern: Inline-volume (xfs)][Slow] volumes
... skipping 170 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy
  test/e2e/storage/framework/testsuite.go:50
    (Always)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed via chgrp in first pod, new pod with different fsgroup applied to the volume contents
    test/e2e/storage/testsuites/fsgroupchangepolicy.go:216
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (Always)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed via chgrp in first pod, new pod with different fsgroup applied to the volume contents","total":244,"completed":51,"skipped":4230,"failed":0}
SSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral 
  should create read-only inline ephemeral volume
  test/e2e/storage/testsuites/ephemeral.go:175
[BeforeEach] [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral
... skipping 38 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral
  test/e2e/storage/framework/testsuite.go:50
    should create read-only inline ephemeral volume
    test/e2e/storage/testsuites/ephemeral.go:175
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral should create read-only inline ephemeral volume","total":244,"completed":52,"skipped":4247,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Inline-volume (ntfs)][Feature:Windows] volumes 
  should allow exec of files on the volume
  test/e2e/storage/testsuites/volumes.go:198
[BeforeEach] [Testpattern: Inline-volume (ntfs)][Feature:Windows] volumes
... skipping 37 lines ...
Sep  6 01:32:36.975: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  6 01:32:36.985: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgkjvj7] to have phase Bound
Sep  6 01:32:36.994: INFO: PersistentVolumeClaim cinder.csi.openstack.orgkjvj7 found but phase is Pending instead of Bound.
Sep  6 01:32:38.999: INFO: PersistentVolumeClaim cinder.csi.openstack.orgkjvj7 found and phase=Bound (2.013673307s)
STEP: [init] starting a pod to use the claim
STEP: [init] check pod success
Sep  6 01:32:39.015: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-gh5cg" in namespace "snapshotting-9043" to be "Succeeded or Failed"
Sep  6 01:32:39.018: INFO: Pod "pvc-snapshottable-tester-gh5cg": Phase="Pending", Reason="", readiness=false. Elapsed: 3.069328ms
Sep  6 01:32:41.023: INFO: Pod "pvc-snapshottable-tester-gh5cg": Phase="Pending", Reason="", readiness=false. Elapsed: 2.007939945s
Sep  6 01:32:43.030: INFO: Pod "pvc-snapshottable-tester-gh5cg": Phase="Pending", Reason="", readiness=false. Elapsed: 4.0145836s
Sep  6 01:32:45.033: INFO: Pod "pvc-snapshottable-tester-gh5cg": Phase="Pending", Reason="", readiness=false. Elapsed: 6.018318714s
Sep  6 01:32:47.046: INFO: Pod "pvc-snapshottable-tester-gh5cg": Phase="Pending", Reason="", readiness=false. Elapsed: 8.031552469s
Sep  6 01:32:49.052: INFO: Pod "pvc-snapshottable-tester-gh5cg": Phase="Pending", Reason="", readiness=false. Elapsed: 10.036673469s
Sep  6 01:32:51.059: INFO: Pod "pvc-snapshottable-tester-gh5cg": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.044188065s
STEP: Saw pod success
Sep  6 01:32:51.059: INFO: Pod "pvc-snapshottable-tester-gh5cg" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
Sep  6 01:32:51.064: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgkjvj7] to have phase Bound
Sep  6 01:32:51.070: INFO: PersistentVolumeClaim cinder.csi.openstack.orgkjvj7 found and phase=Bound (5.821335ms)
STEP: [init] checking the PV
STEP: [init] deleting the pod
Sep  6 01:32:51.105: INFO: Pod pvc-snapshottable-tester-gh5cg has the following logs: 
... skipping 37 lines ...
Sep  6 01:33:05.300: INFO: WaitUntil finished successfully after 2.014678789s
STEP: getting the snapshot and snapshot content
STEP: checking the snapshot
STEP: checking the SnapshotContent
STEP: Modifying source data test
STEP: modifying the data in the source PVC
Sep  6 01:33:05.321: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-data-tester-q2gx5" in namespace "snapshotting-9043" to be "Succeeded or Failed"
Sep  6 01:33:05.324: INFO: Pod "pvc-snapshottable-data-tester-q2gx5": Phase="Pending", Reason="", readiness=false. Elapsed: 3.137874ms
Sep  6 01:33:07.329: INFO: Pod "pvc-snapshottable-data-tester-q2gx5": Phase="Pending", Reason="", readiness=false. Elapsed: 2.007932137s
Sep  6 01:33:09.340: INFO: Pod "pvc-snapshottable-data-tester-q2gx5": Phase="Pending", Reason="", readiness=false. Elapsed: 4.019179364s
Sep  6 01:33:11.346: INFO: Pod "pvc-snapshottable-data-tester-q2gx5": Phase="Pending", Reason="", readiness=false. Elapsed: 6.025239879s
Sep  6 01:33:13.359: INFO: Pod "pvc-snapshottable-data-tester-q2gx5": Phase="Pending", Reason="", readiness=false. Elapsed: 8.037907543s
Sep  6 01:33:15.363: INFO: Pod "pvc-snapshottable-data-tester-q2gx5": Phase="Pending", Reason="", readiness=false. Elapsed: 10.042110934s
Sep  6 01:33:17.369: INFO: Pod "pvc-snapshottable-data-tester-q2gx5": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.047982744s
STEP: Saw pod success
Sep  6 01:33:17.369: INFO: Pod "pvc-snapshottable-data-tester-q2gx5" satisfied condition "Succeeded or Failed"
Sep  6 01:33:17.384: INFO: Pod pvc-snapshottable-data-tester-q2gx5 has the following logs: 
Sep  6 01:33:17.384: INFO: Deleting pod "pvc-snapshottable-data-tester-q2gx5" in namespace "snapshotting-9043"
Sep  6 01:33:17.399: INFO: Wait up to 5m0s for pod "pvc-snapshottable-data-tester-q2gx5" to be fully deleted
STEP: creating a pvc from the snapshot
STEP: starting a pod to use the snapshot
Sep  6 01:33:31.462: INFO: Running '/usr/local/bin/kubectl --server=https://172.24.5.198:6443 --kubeconfig=/root/.kube/config --namespace=snapshotting-9043 exec restored-pvc-tester-lkfml --namespace=snapshotting-9043 -- cat /mnt/test/data'
... skipping 43 lines ...
    test/e2e/storage/testsuites/snapshottable.go:113
      
      test/e2e/storage/testsuites/snapshottable.go:176
        should check snapshot fields, check restore correctly works after modifying source data, check deletion (persistent)
        test/e2e/storage/testsuites/snapshottable.go:278
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned Snapshot (delete policy)] snapshottable[Feature:VolumeSnapshotDataSource] volume snapshot controller  should check snapshot fields, check restore correctly works after modifying source data, check deletion (persistent)","total":244,"completed":53,"skipped":4376,"failed":0}
SSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath 
  should support readOnly directory specified in the volumeMount
  test/e2e/storage/testsuites/subpath.go:367
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
... skipping 14 lines ...

    test/e2e/storage/framework/testsuite.go:121
------------------------------
SSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Inline-volume (default fs)] subPath 
  should fail if non-existent subpath is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:269
[BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
Sep  6 01:34:08.756: INFO: Driver "cinder.csi.openstack.org" does not support volume type "InlineVolume" - skipping
[AfterEach] [Testpattern: Inline-volume (default fs)] subPath
  test/e2e/framework/framework.go:188

S [SKIPPING] in Spec Setup (BeforeEach) [0.000 seconds]
External Storage [Driver: cinder.csi.openstack.org]
test/e2e/storage/external/external.go:174
  [Testpattern: Inline-volume (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if non-existent subpath is outside the volume [Slow][LinuxOnly] [BeforeEach]
    test/e2e/storage/testsuites/subpath.go:269

    Driver "cinder.csi.openstack.org" does not support volume type "InlineVolume" - skipping

    test/e2e/storage/external/external.go:262
------------------------------
... skipping 102 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral
  test/e2e/storage/framework/testsuite.go:50
    should support two pods which have the same volume definition
    test/e2e/storage/testsuites/ephemeral.go:216
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral should support two pods which have the same volume definition","total":244,"completed":54,"skipped":4460,"failed":0}
SSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (ext3)] volumes 
  should allow exec of files on the volume
  test/e2e/storage/testsuites/volumes.go:198
[BeforeEach] [Testpattern: Pre-provisioned PV (ext3)] volumes
... skipping 83 lines ...

    test/e2e/storage/external/external.go:262
------------------------------
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath 
  should fail if subpath directory is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:242
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/framework/framework.go:187
STEP: Creating a kubernetes client
Sep  6 01:35:59.324: INFO: >>> kubeConfig: /root/.kube/config
STEP: Building a namespace api object, basename provisioning
STEP: Waiting for a default service account to be provisioned in namespace
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
[It] should fail if subpath directory is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:242
Sep  6 01:35:59.374: INFO: Creating resource for dynamic PV
Sep  6 01:35:59.374: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(cinder.csi.openstack.org) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-2504-e2e-sctllx4
STEP: creating a claim
Sep  6 01:35:59.400: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  6 01:35:59.423: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgnxg78] to have phase Bound
Sep  6 01:35:59.432: INFO: PersistentVolumeClaim cinder.csi.openstack.orgnxg78 found but phase is Pending instead of Bound.
Sep  6 01:36:01.441: INFO: PersistentVolumeClaim cinder.csi.openstack.orgnxg78 found and phase=Bound (2.017831393s)
STEP: Creating pod pod-subpath-test-dynamicpv-jmtr
STEP: Checking for subpath error in container status
Sep  6 01:36:15.466: INFO: Deleting pod "pod-subpath-test-dynamicpv-jmtr" in namespace "provisioning-2504"
Sep  6 01:36:15.473: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-jmtr" to be fully deleted
STEP: Deleting pod
Sep  6 01:36:17.480: INFO: Deleting pod "pod-subpath-test-dynamicpv-jmtr" in namespace "provisioning-2504"
STEP: Deleting pvc
Sep  6 01:36:17.485: INFO: Deleting PersistentVolumeClaim "cinder.csi.openstack.orgnxg78"
... skipping 11 lines ...

• [SLOW TEST:38.211 seconds]
External Storage [Driver: cinder.csi.openstack.org]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath directory is outside the volume [Slow][LinuxOnly]
    test/e2e/storage/testsuites/subpath.go:242
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath should fail if subpath directory is outside the volume [Slow][LinuxOnly]","total":244,"completed":55,"skipped":4636,"failed":0}
SSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Inline-volume (default fs)] volumes 
  should allow exec of files on the volume
  test/e2e/storage/testsuites/volumes.go:198
[BeforeEach] [Testpattern: Inline-volume (default fs)] volumes
... skipping 37 lines ...
Sep  6 01:36:37.579: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  6 01:36:37.588: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgd5q8g] to have phase Bound
Sep  6 01:36:37.625: INFO: PersistentVolumeClaim cinder.csi.openstack.orgd5q8g found but phase is Pending instead of Bound.
Sep  6 01:36:39.631: INFO: PersistentVolumeClaim cinder.csi.openstack.orgd5q8g found and phase=Bound (2.042769995s)
STEP: [init] starting a pod to use the claim
STEP: [init] check pod success
Sep  6 01:36:39.648: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-wjmtd" in namespace "snapshotting-1026" to be "Succeeded or Failed"
Sep  6 01:36:39.650: INFO: Pod "pvc-snapshottable-tester-wjmtd": Phase="Pending", Reason="", readiness=false. Elapsed: 2.901729ms
Sep  6 01:36:41.658: INFO: Pod "pvc-snapshottable-tester-wjmtd": Phase="Pending", Reason="", readiness=false. Elapsed: 2.01024123s
Sep  6 01:36:43.663: INFO: Pod "pvc-snapshottable-tester-wjmtd": Phase="Pending", Reason="", readiness=false. Elapsed: 4.015505946s
Sep  6 01:36:45.669: INFO: Pod "pvc-snapshottable-tester-wjmtd": Phase="Pending", Reason="", readiness=false. Elapsed: 6.020919953s
Sep  6 01:36:47.684: INFO: Pod "pvc-snapshottable-tester-wjmtd": Phase="Pending", Reason="", readiness=false. Elapsed: 8.036248141s
Sep  6 01:36:49.689: INFO: Pod "pvc-snapshottable-tester-wjmtd": Phase="Pending", Reason="", readiness=false. Elapsed: 10.0409127s
Sep  6 01:36:51.698: INFO: Pod "pvc-snapshottable-tester-wjmtd": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.0502966s
STEP: Saw pod success
Sep  6 01:36:51.698: INFO: Pod "pvc-snapshottable-tester-wjmtd" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
Sep  6 01:36:51.701: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgd5q8g] to have phase Bound
Sep  6 01:36:51.704: INFO: PersistentVolumeClaim cinder.csi.openstack.orgd5q8g found and phase=Bound (3.335211ms)
STEP: [init] checking the PV
STEP: [init] deleting the pod
Sep  6 01:36:51.730: INFO: Pod pvc-snapshottable-tester-wjmtd has the following logs: 
... skipping 13 lines ...
Sep  6 01:36:57.802: INFO: received snapshotStatus map[boundVolumeSnapshotContentName:snapcontent-36b1d6f5-e819-45fd-9e88-4f330a47b70f creationTime:2022-09-06T01:36:56Z readyToUse:true restoreSize:1Gi]
Sep  6 01:36:57.802: INFO: snapshotContentName snapcontent-36b1d6f5-e819-45fd-9e88-4f330a47b70f
STEP: checking the snapshot
STEP: checking the SnapshotContent
STEP: Modifying source data test
STEP: modifying the data in the source PVC
Sep  6 01:36:57.818: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-data-tester-c6wrc" in namespace "snapshotting-1026" to be "Succeeded or Failed"
Sep  6 01:36:57.820: INFO: Pod "pvc-snapshottable-data-tester-c6wrc": Phase="Pending", Reason="", readiness=false. Elapsed: 2.725723ms
Sep  6 01:36:59.826: INFO: Pod "pvc-snapshottable-data-tester-c6wrc": Phase="Pending", Reason="", readiness=false. Elapsed: 2.008805792s
Sep  6 01:37:01.831: INFO: Pod "pvc-snapshottable-data-tester-c6wrc": Phase="Pending", Reason="", readiness=false. Elapsed: 4.013070419s
Sep  6 01:37:03.835: INFO: Pod "pvc-snapshottable-data-tester-c6wrc": Phase="Pending", Reason="", readiness=false. Elapsed: 6.017433737s
Sep  6 01:37:05.840: INFO: Pod "pvc-snapshottable-data-tester-c6wrc": Phase="Pending", Reason="", readiness=false. Elapsed: 8.022043859s
Sep  6 01:37:07.845: INFO: Pod "pvc-snapshottable-data-tester-c6wrc": Phase="Pending", Reason="", readiness=false. Elapsed: 10.026892516s
Sep  6 01:37:09.851: INFO: Pod "pvc-snapshottable-data-tester-c6wrc": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.033363292s
STEP: Saw pod success
Sep  6 01:37:09.851: INFO: Pod "pvc-snapshottable-data-tester-c6wrc" satisfied condition "Succeeded or Failed"
Sep  6 01:37:09.862: INFO: Pod pvc-snapshottable-data-tester-c6wrc has the following logs: 
Sep  6 01:37:09.862: INFO: Deleting pod "pvc-snapshottable-data-tester-c6wrc" in namespace "snapshotting-1026"
Sep  6 01:37:09.871: INFO: Wait up to 5m0s for pod "pvc-snapshottable-data-tester-c6wrc" to be fully deleted
STEP: creating a pvc from the snapshot
STEP: starting a pod to use the snapshot
Sep  6 01:37:19.907: INFO: Running '/usr/local/bin/kubectl --server=https://172.24.5.198:6443 --kubeconfig=/root/.kube/config --namespace=snapshotting-1026 exec restored-pvc-tester-44srd --namespace=snapshotting-1026 -- cat /mnt/test/data'
... skipping 35 lines ...
Sep  6 01:37:44.264: INFO: volumesnapshotcontents snapcontent-36b1d6f5-e819-45fd-9e88-4f330a47b70f has been found and is not deleted
Sep  6 01:37:45.269: INFO: volumesnapshotcontents snapcontent-36b1d6f5-e819-45fd-9e88-4f330a47b70f has been found and is not deleted
Sep  6 01:37:46.276: INFO: volumesnapshotcontents snapcontent-36b1d6f5-e819-45fd-9e88-4f330a47b70f has been found and is not deleted
Sep  6 01:37:47.283: INFO: volumesnapshotcontents snapcontent-36b1d6f5-e819-45fd-9e88-4f330a47b70f has been found and is not deleted
Sep  6 01:37:48.288: INFO: volumesnapshotcontents snapcontent-36b1d6f5-e819-45fd-9e88-4f330a47b70f has been found and is not deleted
Sep  6 01:37:49.297: INFO: volumesnapshotcontents snapcontent-36b1d6f5-e819-45fd-9e88-4f330a47b70f has been found and is not deleted
Sep  6 01:37:50.298: INFO: WaitUntil failed after reaching the timeout 30s
[AfterEach] volume snapshot controller
  test/e2e/storage/testsuites/snapshottable.go:172
Sep  6 01:37:50.307: INFO: Pod restored-pvc-tester-44srd has the following logs: 
Sep  6 01:37:50.307: INFO: Deleting pod "restored-pvc-tester-44srd" in namespace "snapshotting-1026"
Sep  6 01:37:50.310: INFO: Wait up to 5m0s for pod "restored-pvc-tester-44srd" to be fully deleted
Sep  6 01:37:54.319: INFO: deleting claim "snapshotting-1026"/"pvc-vjfws"
... skipping 27 lines ...
    test/e2e/storage/testsuites/snapshottable.go:113
      
      test/e2e/storage/testsuites/snapshottable.go:176
        should check snapshot fields, check restore correctly works after modifying source data, check deletion (persistent)
        test/e2e/storage/testsuites/snapshottable.go:278
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic Snapshot (retain policy)] snapshottable[Feature:VolumeSnapshotDataSource] volume snapshot controller  should check snapshot fields, check restore correctly works after modifying source data, check deletion (persistent)","total":244,"completed":56,"skipped":4687,"failed":0}
SS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (filesystem volmode)] multiVolume [Slow] 
  should concurrently access the single volume from pods on different node
  test/e2e/storage/testsuites/multivolume.go:451
[BeforeEach] [Testpattern: Pre-provisioned PV (filesystem volmode)] multiVolume [Slow]
... skipping 173 lines ...
Sep  6 01:38:01.555: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  6 01:38:01.569: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.org7zpbr] to have phase Bound
Sep  6 01:38:01.585: INFO: PersistentVolumeClaim cinder.csi.openstack.org7zpbr found but phase is Pending instead of Bound.
Sep  6 01:38:03.589: INFO: PersistentVolumeClaim cinder.csi.openstack.org7zpbr found and phase=Bound (2.02027061s)
STEP: Creating pod pod-subpath-test-dynamicpv-5j85
STEP: Creating a pod to test atomic-volume-subpath
Sep  6 01:38:03.602: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-5j85" in namespace "provisioning-8525" to be "Succeeded or Failed"
Sep  6 01:38:03.612: INFO: Pod "pod-subpath-test-dynamicpv-5j85": Phase="Pending", Reason="", readiness=false. Elapsed: 10.690039ms
Sep  6 01:38:05.617: INFO: Pod "pod-subpath-test-dynamicpv-5j85": Phase="Pending", Reason="", readiness=false. Elapsed: 2.015753886s
Sep  6 01:38:07.622: INFO: Pod "pod-subpath-test-dynamicpv-5j85": Phase="Pending", Reason="", readiness=false. Elapsed: 4.019834843s
Sep  6 01:38:09.626: INFO: Pod "pod-subpath-test-dynamicpv-5j85": Phase="Pending", Reason="", readiness=false. Elapsed: 6.023833504s
Sep  6 01:38:11.644: INFO: Pod "pod-subpath-test-dynamicpv-5j85": Phase="Pending", Reason="", readiness=false. Elapsed: 8.042079532s
Sep  6 01:38:13.655: INFO: Pod "pod-subpath-test-dynamicpv-5j85": Phase="Pending", Reason="", readiness=false. Elapsed: 10.053493215s
... skipping 7 lines ...
Sep  6 01:38:29.698: INFO: Pod "pod-subpath-test-dynamicpv-5j85": Phase="Running", Reason="", readiness=true. Elapsed: 26.095970373s
Sep  6 01:38:31.702: INFO: Pod "pod-subpath-test-dynamicpv-5j85": Phase="Running", Reason="", readiness=true. Elapsed: 28.100603931s
Sep  6 01:38:33.708: INFO: Pod "pod-subpath-test-dynamicpv-5j85": Phase="Running", Reason="", readiness=true. Elapsed: 30.106532637s
Sep  6 01:38:35.713: INFO: Pod "pod-subpath-test-dynamicpv-5j85": Phase="Running", Reason="", readiness=false. Elapsed: 32.111351199s
Sep  6 01:38:37.718: INFO: Pod "pod-subpath-test-dynamicpv-5j85": Phase="Succeeded", Reason="", readiness=false. Elapsed: 34.116277107s
STEP: Saw pod success
Sep  6 01:38:37.718: INFO: Pod "pod-subpath-test-dynamicpv-5j85" satisfied condition "Succeeded or Failed"
Sep  6 01:38:37.722: INFO: Trying to get logs from node k3s-master pod pod-subpath-test-dynamicpv-5j85 container test-container-subpath-dynamicpv-5j85: <nil>
STEP: delete the pod
Sep  6 01:38:37.745: INFO: Waiting for pod pod-subpath-test-dynamicpv-5j85 to disappear
Sep  6 01:38:37.751: INFO: Pod pod-subpath-test-dynamicpv-5j85 no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-5j85
Sep  6 01:38:37.751: INFO: Deleting pod "pod-subpath-test-dynamicpv-5j85" in namespace "provisioning-8525"
... skipping 18 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should support file as subpath [LinuxOnly]
    test/e2e/storage/testsuites/subpath.go:232
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath should support file as subpath [LinuxOnly]","total":244,"completed":57,"skipped":4817,"failed":0}
SSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ext4)] volumes 
  should store data
  test/e2e/storage/testsuites/volumes.go:161
[BeforeEach] [Testpattern: Dynamic PV (ext4)] volumes
... skipping 100 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (ext4)] volumes
  test/e2e/storage/framework/testsuite.go:50
    should store data
    test/e2e/storage/testsuites/volumes.go:161
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ext4)] volumes should store data","total":244,"completed":58,"skipped":4835,"failed":0}
SSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Ephemeral Snapshot (retain policy)] snapshottable[Feature:VolumeSnapshotDataSource] volume snapshot controller  
  should check snapshot fields, check restore correctly works after modifying source data, check deletion (persistent)
  test/e2e/storage/testsuites/snapshottable.go:278
[BeforeEach] [Testpattern: Ephemeral Snapshot (retain policy)] snapshottable[Feature:VolumeSnapshotDataSource]
... skipping 7 lines ...
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
[It] should check snapshot fields, check restore correctly works after modifying source data, check deletion (persistent)
  test/e2e/storage/testsuites/snapshottable.go:278
Sep  6 01:39:33.870: INFO: volume type "GenericEphemeralVolume" is ephemeral
[AfterEach] volume snapshot controller
  test/e2e/storage/testsuites/snapshottable.go:172
Sep  6 01:39:33.878: INFO: Error getting logs for pod restored-pvc-tester-48hpr: the server could not find the requested resource (get pods restored-pvc-tester-48hpr)
Sep  6 01:39:33.878: INFO: Deleting pod "restored-pvc-tester-48hpr" in namespace "snapshotting-1266"
Sep  6 01:39:33.884: INFO: deleting snapshot content "snapcontent-d16919f6-2512-4dad-8988-4bceb6b299be"
Sep  6 01:39:33.889: INFO: deleting snapshot class "snapshotting-1266rlg6p"
Sep  6 01:39:33.892: INFO: Waiting up to 5m0s for volumesnapshotclasses snapshotting-1266rlg6p to be deleted
Sep  6 01:39:33.897: INFO: volumesnapshotclasses snapshotting-1266rlg6p is not found and has been deleted
Sep  6 01:39:33.897: INFO: WaitUntil finished successfully after 5.080855ms
... skipping 135 lines ...

    test/e2e/storage/framework/testsuite.go:121
------------------------------
SSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (block volmode)] volumeMode 
  should fail to use a volume in a pod with mismatched mode [Slow]
  test/e2e/storage/testsuites/volumemode.go:299
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] volumeMode
  test/e2e/framework/framework.go:187
STEP: Creating a kubernetes client
Sep  6 01:39:33.922: INFO: >>> kubeConfig: /root/.kube/config
STEP: Building a namespace api object, basename volumemode
STEP: Waiting for a default service account to be provisioned in namespace
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
[It] should fail to use a volume in a pod with mismatched mode [Slow]
  test/e2e/storage/testsuites/volumemode.go:299
Sep  6 01:39:33.947: INFO: Creating resource for dynamic PV
Sep  6 01:39:33.947: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(cinder.csi.openstack.org) supported size:{ 1Mi} 
STEP: creating a StorageClass volumemode-989-e2e-scjtz88
STEP: creating a claim
Sep  6 01:39:33.963: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.org4pdgj] to have phase Bound
Sep  6 01:39:33.974: INFO: PersistentVolumeClaim cinder.csi.openstack.org4pdgj found but phase is Pending instead of Bound.
Sep  6 01:39:35.978: INFO: PersistentVolumeClaim cinder.csi.openstack.org4pdgj found and phase=Bound (2.015950774s)
STEP: Creating pod
STEP: Waiting for the pod to fail
Sep  6 01:39:38.004: INFO: Deleting pod "pod-fbb735c7-5605-4beb-93c9-1e22e8079f64" in namespace "volumemode-989"
Sep  6 01:39:38.012: INFO: Wait up to 5m0s for pod "pod-fbb735c7-5605-4beb-93c9-1e22e8079f64" to be fully deleted
STEP: Deleting pvc
Sep  6 01:39:40.023: INFO: Deleting PersistentVolumeClaim "cinder.csi.openstack.org4pdgj"
Sep  6 01:39:40.030: INFO: Waiting up to 5m0s for PersistentVolume pvc-1b819bab-7af5-4104-989b-56533f715128 to get deleted
Sep  6 01:39:40.036: INFO: PersistentVolume pvc-1b819bab-7af5-4104-989b-56533f715128 found and phase=Bound (5.634106ms)
... skipping 7 lines ...

• [SLOW TEST:16.144 seconds]
External Storage [Driver: cinder.csi.openstack.org]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (block volmode)] volumeMode
  test/e2e/storage/framework/testsuite.go:50
    should fail to use a volume in a pod with mismatched mode [Slow]
    test/e2e/storage/testsuites/volumemode.go:299
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (block volmode)] volumeMode should fail to use a volume in a pod with mismatched mode [Slow]","total":244,"completed":59,"skipped":5089,"failed":0}
SSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] provisioning 
  should provision storage with mount options
  test/e2e/storage/testsuites/provisioning.go:187
[BeforeEach] [Testpattern: Dynamic PV (default fs)] provisioning
... skipping 82 lines ...

    test/e2e/storage/external/external.go:262
------------------------------
SSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (default fs)] subPath 
  should fail if non-existent subpath is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:269
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
Sep  6 01:39:50.175: INFO: Driver "cinder.csi.openstack.org" does not support volume type "PreprovisionedPV" - skipping
[AfterEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/framework/framework.go:188

S [SKIPPING] in Spec Setup (BeforeEach) [0.000 seconds]
External Storage [Driver: cinder.csi.openstack.org]
test/e2e/storage/external/external.go:174
  [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if non-existent subpath is outside the volume [Slow][LinuxOnly] [BeforeEach]
    test/e2e/storage/testsuites/subpath.go:269

    Driver "cinder.csi.openstack.org" does not support volume type "PreprovisionedPV" - skipping

    test/e2e/storage/external/external.go:262
------------------------------
... skipping 66 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Generic Ephemeral-volume (block volmode) (late-binding)] ephemeral
  test/e2e/storage/framework/testsuite.go:50
    should support multiple inline ephemeral volumes
    test/e2e/storage/testsuites/ephemeral.go:254
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Generic Ephemeral-volume (block volmode) (late-binding)] ephemeral should support multiple inline ephemeral volumes","total":244,"completed":60,"skipped":5249,"failed":0}
SSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] volume-stress 
  multiple pods should access different volumes repeatedly [Slow] [Serial]
  test/e2e/storage/testsuites/volume_stress.go:205
[BeforeEach] [Testpattern: Dynamic PV (default fs)] volume-stress
... skipping 37 lines ...
Sep  6 01:40:57.523: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  6 01:40:57.533: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgc849w] to have phase Bound
Sep  6 01:40:57.548: INFO: PersistentVolumeClaim cinder.csi.openstack.orgc849w found but phase is Pending instead of Bound.
Sep  6 01:40:59.553: INFO: PersistentVolumeClaim cinder.csi.openstack.orgc849w found and phase=Bound (2.020130358s)
STEP: Creating pod pod-subpath-test-dynamicpv-v6tg
STEP: Creating a pod to test subpath
Sep  6 01:40:59.568: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-v6tg" in namespace "provisioning-5214" to be "Succeeded or Failed"
Sep  6 01:40:59.575: INFO: Pod "pod-subpath-test-dynamicpv-v6tg": Phase="Pending", Reason="", readiness=false. Elapsed: 7.509707ms
Sep  6 01:41:01.580: INFO: Pod "pod-subpath-test-dynamicpv-v6tg": Phase="Pending", Reason="", readiness=false. Elapsed: 2.012393529s
Sep  6 01:41:03.586: INFO: Pod "pod-subpath-test-dynamicpv-v6tg": Phase="Pending", Reason="", readiness=false. Elapsed: 4.017809005s
Sep  6 01:41:05.598: INFO: Pod "pod-subpath-test-dynamicpv-v6tg": Phase="Pending", Reason="", readiness=false. Elapsed: 6.030536145s
Sep  6 01:41:07.608: INFO: Pod "pod-subpath-test-dynamicpv-v6tg": Phase="Pending", Reason="", readiness=false. Elapsed: 8.039859794s
Sep  6 01:41:09.612: INFO: Pod "pod-subpath-test-dynamicpv-v6tg": Phase="Pending", Reason="", readiness=false. Elapsed: 10.04384748s
Sep  6 01:41:11.617: INFO: Pod "pod-subpath-test-dynamicpv-v6tg": Phase="Pending", Reason="", readiness=false. Elapsed: 12.049530676s
Sep  6 01:41:13.622: INFO: Pod "pod-subpath-test-dynamicpv-v6tg": Phase="Pending", Reason="", readiness=false. Elapsed: 14.054214623s
Sep  6 01:41:15.628: INFO: Pod "pod-subpath-test-dynamicpv-v6tg": Phase="Pending", Reason="", readiness=false. Elapsed: 16.060106367s
Sep  6 01:41:17.633: INFO: Pod "pod-subpath-test-dynamicpv-v6tg": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.065634866s
STEP: Saw pod success
Sep  6 01:41:17.633: INFO: Pod "pod-subpath-test-dynamicpv-v6tg" satisfied condition "Succeeded or Failed"
Sep  6 01:41:17.637: INFO: Trying to get logs from node k3s-master pod pod-subpath-test-dynamicpv-v6tg container test-container-subpath-dynamicpv-v6tg: <nil>
STEP: delete the pod
Sep  6 01:41:17.669: INFO: Waiting for pod pod-subpath-test-dynamicpv-v6tg to disappear
Sep  6 01:41:17.680: INFO: Pod pod-subpath-test-dynamicpv-v6tg no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-v6tg
Sep  6 01:41:17.680: INFO: Deleting pod "pod-subpath-test-dynamicpv-v6tg" in namespace "provisioning-5214"
... skipping 16 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should support readOnly file specified in the volumeMount [LinuxOnly]
    test/e2e/storage/testsuites/subpath.go:382
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath should support readOnly file specified in the volumeMount [LinuxOnly]","total":244,"completed":61,"skipped":5260,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] volumes 
  should allow exec of files on the volume
  test/e2e/storage/testsuites/volumes.go:198
[BeforeEach] [Testpattern: Dynamic PV (default fs)] volumes
... skipping 14 lines ...
Sep  6 01:41:27.813: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  6 01:41:27.824: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgj7599] to have phase Bound
Sep  6 01:41:27.831: INFO: PersistentVolumeClaim cinder.csi.openstack.orgj7599 found but phase is Pending instead of Bound.
Sep  6 01:41:29.839: INFO: PersistentVolumeClaim cinder.csi.openstack.orgj7599 found and phase=Bound (2.014626503s)
STEP: Creating pod exec-volume-test-dynamicpv-cmwq
STEP: Creating a pod to test exec-volume-test
Sep  6 01:41:29.871: INFO: Waiting up to 5m0s for pod "exec-volume-test-dynamicpv-cmwq" in namespace "volume-5714" to be "Succeeded or Failed"
Sep  6 01:41:29.893: INFO: Pod "exec-volume-test-dynamicpv-cmwq": Phase="Pending", Reason="", readiness=false. Elapsed: 21.493163ms
Sep  6 01:41:31.899: INFO: Pod "exec-volume-test-dynamicpv-cmwq": Phase="Pending", Reason="", readiness=false. Elapsed: 2.028032475s
Sep  6 01:41:33.905: INFO: Pod "exec-volume-test-dynamicpv-cmwq": Phase="Pending", Reason="", readiness=false. Elapsed: 4.033583903s
Sep  6 01:41:35.911: INFO: Pod "exec-volume-test-dynamicpv-cmwq": Phase="Pending", Reason="", readiness=false. Elapsed: 6.039325209s
Sep  6 01:41:37.915: INFO: Pod "exec-volume-test-dynamicpv-cmwq": Phase="Pending", Reason="", readiness=false. Elapsed: 8.043778569s
Sep  6 01:41:39.920: INFO: Pod "exec-volume-test-dynamicpv-cmwq": Phase="Pending", Reason="", readiness=false. Elapsed: 10.048788229s
Sep  6 01:41:41.925: INFO: Pod "exec-volume-test-dynamicpv-cmwq": Phase="Pending", Reason="", readiness=false. Elapsed: 12.053537345s
Sep  6 01:41:43.930: INFO: Pod "exec-volume-test-dynamicpv-cmwq": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.058468998s
STEP: Saw pod success
Sep  6 01:41:43.930: INFO: Pod "exec-volume-test-dynamicpv-cmwq" satisfied condition "Succeeded or Failed"
Sep  6 01:41:43.933: INFO: Trying to get logs from node k3s-master pod exec-volume-test-dynamicpv-cmwq container exec-container-dynamicpv-cmwq: <nil>
STEP: delete the pod
Sep  6 01:41:43.952: INFO: Waiting for pod exec-volume-test-dynamicpv-cmwq to disappear
Sep  6 01:41:43.959: INFO: Pod exec-volume-test-dynamicpv-cmwq no longer exists
STEP: Deleting pod exec-volume-test-dynamicpv-cmwq
Sep  6 01:41:43.959: INFO: Deleting pod "exec-volume-test-dynamicpv-cmwq" in namespace "volume-5714"
... skipping 16 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] volumes
  test/e2e/storage/framework/testsuite.go:50
    should allow exec of files on the volume
    test/e2e/storage/testsuites/volumes.go:198
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] volumes should allow exec of files on the volume","total":244,"completed":62,"skipped":5289,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (xfs)][Slow] volumes 
  should store data
  test/e2e/storage/testsuites/volumes.go:161
[BeforeEach] [Testpattern: Pre-provisioned PV (xfs)][Slow] volumes
... skipping 14 lines ...

    test/e2e/storage/external/external.go:262
------------------------------
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (filesystem volmode)] volumeMode 
  should fail to use a volume in a pod with mismatched mode [Slow]
  test/e2e/storage/testsuites/volumemode.go:299
[BeforeEach] [Testpattern: Pre-provisioned PV (filesystem volmode)] volumeMode
  test/e2e/storage/framework/testsuite.go:51
Sep  6 01:42:04.035: INFO: Driver "cinder.csi.openstack.org" does not support volume type "PreprovisionedPV" - skipping
[AfterEach] [Testpattern: Pre-provisioned PV (filesystem volmode)] volumeMode
  test/e2e/framework/framework.go:188

S [SKIPPING] in Spec Setup (BeforeEach) [0.000 seconds]
External Storage [Driver: cinder.csi.openstack.org]
test/e2e/storage/external/external.go:174
  [Testpattern: Pre-provisioned PV (filesystem volmode)] volumeMode
  test/e2e/storage/framework/testsuite.go:50
    should fail to use a volume in a pod with mismatched mode [Slow] [BeforeEach]
    test/e2e/storage/testsuites/volumemode.go:299

    Driver "cinder.csi.openstack.org" does not support volume type "PreprovisionedPV" - skipping

    test/e2e/storage/external/external.go:262
------------------------------
... skipping 157 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (ext4)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should concurrently access the volume and restored snapshot from pods on the same node [LinuxOnly][Feature:VolumeSnapshotDataSource][Feature:VolumeSourceXFS]
    test/e2e/storage/testsuites/multivolume.go:323
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ext4)] multiVolume [Slow] should concurrently access the volume and restored snapshot from pods on the same node [LinuxOnly][Feature:VolumeSnapshotDataSource][Feature:VolumeSourceXFS]","total":244,"completed":63,"skipped":5559,"failed":0}
SSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ntfs)(allowExpansion)][Feature:Windows] volume-expand 
  should resize volume when PVC is edited while pod is using it
  test/e2e/storage/testsuites/volume_expand.go:248
[BeforeEach] [Testpattern: Dynamic PV (ntfs)(allowExpansion)][Feature:Windows] volume-expand
... skipping 60 lines ...

    test/e2e/storage/framework/testsuite.go:121
------------------------------
SS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (filesystem volmode)] volumeMode 
  should fail to use a volume in a pod with mismatched mode [Slow]
  test/e2e/storage/testsuites/volumemode.go:299
[BeforeEach] [Testpattern: Dynamic PV (filesystem volmode)] volumeMode
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (filesystem volmode)] volumeMode
  test/e2e/framework/framework.go:187
STEP: Creating a kubernetes client
Sep  6 01:43:01.755: INFO: >>> kubeConfig: /root/.kube/config
STEP: Building a namespace api object, basename volumemode
STEP: Waiting for a default service account to be provisioned in namespace
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
[It] should fail to use a volume in a pod with mismatched mode [Slow]
  test/e2e/storage/testsuites/volumemode.go:299
Sep  6 01:43:01.837: INFO: Creating resource for dynamic PV
Sep  6 01:43:01.837: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(cinder.csi.openstack.org) supported size:{ 1Mi} 
STEP: creating a StorageClass volumemode-130-e2e-sc7gj9n
STEP: creating a claim
Sep  6 01:43:01.858: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.org8pbd6] to have phase Bound
Sep  6 01:43:01.871: INFO: PersistentVolumeClaim cinder.csi.openstack.org8pbd6 found but phase is Pending instead of Bound.
Sep  6 01:43:03.875: INFO: PersistentVolumeClaim cinder.csi.openstack.org8pbd6 found and phase=Bound (2.01713924s)
STEP: Creating pod
STEP: Waiting for the pod to fail
Sep  6 01:43:05.901: INFO: Deleting pod "pod-72b6c034-6f9b-42cb-8d52-194a7d204784" in namespace "volumemode-130"
Sep  6 01:43:05.910: INFO: Wait up to 5m0s for pod "pod-72b6c034-6f9b-42cb-8d52-194a7d204784" to be fully deleted
STEP: Deleting pvc
Sep  6 01:43:07.919: INFO: Deleting PersistentVolumeClaim "cinder.csi.openstack.org8pbd6"
Sep  6 01:43:07.928: INFO: Waiting up to 5m0s for PersistentVolume pvc-0c012379-2aa7-471e-a20c-5f9d42ce49b1 to get deleted
Sep  6 01:43:07.932: INFO: PersistentVolume pvc-0c012379-2aa7-471e-a20c-5f9d42ce49b1 found and phase=Bound (4.195958ms)
... skipping 7 lines ...

• [SLOW TEST:16.201 seconds]
External Storage [Driver: cinder.csi.openstack.org]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (filesystem volmode)] volumeMode
  test/e2e/storage/framework/testsuite.go:50
    should fail to use a volume in a pod with mismatched mode [Slow]
    test/e2e/storage/testsuites/volumemode.go:299
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (filesystem volmode)] volumeMode should fail to use a volume in a pod with mismatched mode [Slow]","total":244,"completed":64,"skipped":5645,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy 
  (Always)[LinuxOnly], pod created with an initial fsgroup, new pod fsgroup applied to volume contents
  test/e2e/storage/testsuites/fsgroupchangepolicy.go:216
[BeforeEach] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy
... skipping 81 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy
  test/e2e/storage/framework/testsuite.go:50
    (Always)[LinuxOnly], pod created with an initial fsgroup, new pod fsgroup applied to volume contents
    test/e2e/storage/testsuites/fsgroupchangepolicy.go:216
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (Always)[LinuxOnly], pod created with an initial fsgroup, new pod fsgroup applied to volume contents","total":244,"completed":65,"skipped":5693,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Generic Ephemeral-volume (block volmode) (late-binding)] ephemeral 
  should support two pods which have the same volume definition
  test/e2e/storage/testsuites/ephemeral.go:216
[BeforeEach] [Testpattern: Generic Ephemeral-volume (block volmode) (late-binding)] ephemeral
... skipping 41 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Generic Ephemeral-volume (block volmode) (late-binding)] ephemeral
  test/e2e/storage/framework/testsuite.go:50
    should support two pods which have the same volume definition
    test/e2e/storage/testsuites/ephemeral.go:216
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Generic Ephemeral-volume (block volmode) (late-binding)] ephemeral should support two pods which have the same volume definition","total":244,"completed":66,"skipped":5716,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Inline-volume (default fs)] subPath 
  should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:280
[BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
Sep  6 01:45:50.805: INFO: Driver "cinder.csi.openstack.org" does not support volume type "InlineVolume" - skipping
[AfterEach] [Testpattern: Inline-volume (default fs)] subPath
  test/e2e/framework/framework.go:188

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: cinder.csi.openstack.org]
test/e2e/storage/external/external.go:174
  [Testpattern: Inline-volume (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath with backstepping is outside the volume [Slow][LinuxOnly] [BeforeEach]
    test/e2e/storage/testsuites/subpath.go:280

    Driver "cinder.csi.openstack.org" does not support volume type "InlineVolume" - skipping

    test/e2e/storage/external/external.go:262
------------------------------
... skipping 128 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (block volmode)] volumes
  test/e2e/storage/framework/testsuite.go:50
    should store data
    test/e2e/storage/testsuites/volumes.go:161
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (block volmode)] volumes should store data","total":244,"completed":67,"skipped":5875,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Inline-volume (default fs)] subPath 
  should fail if subpath directory is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:242
[BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
Sep  6 01:46:31.309: INFO: Driver "cinder.csi.openstack.org" does not support volume type "InlineVolume" - skipping
[AfterEach] [Testpattern: Inline-volume (default fs)] subPath
  test/e2e/framework/framework.go:188

S [SKIPPING] in Spec Setup (BeforeEach) [0.000 seconds]
External Storage [Driver: cinder.csi.openstack.org]
test/e2e/storage/external/external.go:174
  [Testpattern: Inline-volume (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath directory is outside the volume [Slow][LinuxOnly] [BeforeEach]
    test/e2e/storage/testsuites/subpath.go:242

    Driver "cinder.csi.openstack.org" does not support volume type "InlineVolume" - skipping

    test/e2e/storage/external/external.go:262
------------------------------
... skipping 14 lines ...
[It] should check snapshot fields, check restore correctly works, check deletion (ephemeral)
  test/e2e/storage/testsuites/snapshottable.go:177
Sep  6 01:46:31.355: INFO: Creating resource for dynamic PV
Sep  6 01:46:31.355: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(cinder.csi.openstack.org) supported size:{ 1Mi} 
STEP: creating a StorageClass snapshotting-6990-e2e-sczpzdw
STEP: [init] starting a pod to use the claim
Sep  6 01:46:31.376: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-sq4gk" in namespace "snapshotting-6990" to be "Succeeded or Failed"
Sep  6 01:46:31.395: INFO: Pod "pvc-snapshottable-tester-sq4gk": Phase="Pending", Reason="", readiness=false. Elapsed: 18.887047ms
Sep  6 01:46:33.400: INFO: Pod "pvc-snapshottable-tester-sq4gk": Phase="Pending", Reason="", readiness=false. Elapsed: 2.024322982s
Sep  6 01:46:35.406: INFO: Pod "pvc-snapshottable-tester-sq4gk": Phase="Pending", Reason="", readiness=false. Elapsed: 4.02996234s
Sep  6 01:46:37.411: INFO: Pod "pvc-snapshottable-tester-sq4gk": Phase="Pending", Reason="", readiness=false. Elapsed: 6.035789973s
Sep  6 01:46:39.417: INFO: Pod "pvc-snapshottable-tester-sq4gk": Phase="Pending", Reason="", readiness=false. Elapsed: 8.041410206s
Sep  6 01:46:41.422: INFO: Pod "pvc-snapshottable-tester-sq4gk": Phase="Running", Reason="", readiness=true. Elapsed: 10.046262117s
Sep  6 01:46:43.429: INFO: Pod "pvc-snapshottable-tester-sq4gk": Phase="Running", Reason="", readiness=false. Elapsed: 12.053429586s
Sep  6 01:46:45.433: INFO: Pod "pvc-snapshottable-tester-sq4gk": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.057524052s
STEP: Saw pod success
Sep  6 01:46:45.433: INFO: Pod "pvc-snapshottable-tester-sq4gk" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
STEP: creating a SnapshotClass
STEP: creating a dynamic VolumeSnapshot
Sep  6 01:46:45.464: INFO: Waiting up to 5m0s for VolumeSnapshot snapshot-4f24n to become ready
Sep  6 01:46:45.470: INFO: VolumeSnapshot snapshot-4f24n found but is not ready.
Sep  6 01:46:47.475: INFO: VolumeSnapshot snapshot-4f24n found but is not ready.
... skipping 48 lines ...
    test/e2e/storage/testsuites/snapshottable.go:113
      
      test/e2e/storage/testsuites/snapshottable.go:176
        should check snapshot fields, check restore correctly works, check deletion (ephemeral)
        test/e2e/storage/testsuites/snapshottable.go:177
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Ephemeral Snapshot (delete policy)] snapshottable[Feature:VolumeSnapshotDataSource] volume snapshot controller  should check snapshot fields, check restore correctly works, check deletion (ephemeral)","total":244,"completed":68,"skipped":5913,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ext4)] multiVolume [Slow] 
  should concurrently access the single volume from pods on the same node
  test/e2e/storage/testsuites/multivolume.go:298
[BeforeEach] [Testpattern: Dynamic PV (ext4)] multiVolume [Slow]
... skipping 140 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (ext4)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should concurrently access the single volume from pods on the same node
    test/e2e/storage/testsuites/multivolume.go:298
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ext4)] multiVolume [Slow] should concurrently access the single volume from pods on the same node","total":244,"completed":69,"skipped":5962,"failed":0}
SSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (block volmode)] volumeMode 
  should not mount / map unused volumes in a pod [LinuxOnly]
  test/e2e/storage/testsuites/volumemode.go:354
[BeforeEach] [Testpattern: Pre-provisioned PV (block volmode)] volumeMode
... skipping 51 lines ...
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
[It] should check snapshot fields, check restore correctly works, check deletion (ephemeral)
  test/e2e/storage/testsuites/snapshottable.go:177
Sep  6 01:48:20.388: INFO: volume type "DynamicPV" is not ephemeral
[AfterEach] volume snapshot controller
  test/e2e/storage/testsuites/snapshottable.go:172
Sep  6 01:48:20.393: INFO: Error getting logs for pod restored-pvc-tester-pm546: the server could not find the requested resource (get pods restored-pvc-tester-pm546)
Sep  6 01:48:20.393: INFO: Deleting pod "restored-pvc-tester-pm546" in namespace "snapshotting-4197"
Sep  6 01:48:20.397: INFO: deleting claim "snapshotting-4197"/"pvc-46hml"
Sep  6 01:48:20.400: INFO: deleting snapshot content "pre-provisioned-snapcontent-aad910ad-2062-4653-bfb9-661bc0469ba2"
Sep  6 01:48:20.403: INFO: deleting snapshot class "snapshotting-4197q4q86"
Sep  6 01:48:20.408: INFO: Waiting up to 5m0s for volumesnapshotclasses snapshotting-4197q4q86 to be deleted
Sep  6 01:48:20.410: INFO: volumesnapshotclasses snapshotting-4197q4q86 is not found and has been deleted
... skipping 24 lines ...

        test/e2e/storage/testsuites/snapshottable.go:179
------------------------------
SSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (default fs)] subPath 
  should fail if subpath directory is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:242
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
Sep  6 01:48:20.433: INFO: Driver "cinder.csi.openstack.org" does not support volume type "PreprovisionedPV" - skipping
[AfterEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/framework/framework.go:188

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: cinder.csi.openstack.org]
test/e2e/storage/external/external.go:174
  [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath directory is outside the volume [Slow][LinuxOnly] [BeforeEach]
    test/e2e/storage/testsuites/subpath.go:242

    Driver "cinder.csi.openstack.org" does not support volume type "PreprovisionedPV" - skipping

    test/e2e/storage/external/external.go:262
------------------------------
... skipping 145 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should concurrently access the single volume from pods on the same node
    test/e2e/storage/testsuites/multivolume.go:298
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] should concurrently access the single volume from pods on the same node","total":244,"completed":70,"skipped":6020,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: CSI Ephemeral-volume (default fs)] ephemeral 
  should create read-only inline ephemeral volume
  test/e2e/storage/testsuites/ephemeral.go:175
[BeforeEach] [Testpattern: CSI Ephemeral-volume (default fs)] ephemeral
... skipping 135 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should support restarting containers using directory as subpath [Slow]
    test/e2e/storage/testsuites/subpath.go:322
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath should support restarting containers using directory as subpath [Slow]","total":244,"completed":71,"skipped":6104,"failed":0}
SSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] provisioning 
  should provision storage with pvc data source
  test/e2e/storage/testsuites/provisioning.go:421
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] provisioning
... skipping 204 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (block volmode)] provisioning
  test/e2e/storage/framework/testsuite.go:50
    should provision storage with snapshot data source [Feature:VolumeSnapshotDataSource]
    test/e2e/storage/testsuites/provisioning.go:208
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (block volmode)] provisioning should provision storage with snapshot data source [Feature:VolumeSnapshotDataSource]","total":244,"completed":72,"skipped":6164,"failed":0}
SSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath 
  should support existing directory
  test/e2e/storage/testsuites/subpath.go:207
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
... skipping 60 lines ...
Sep  6 01:51:55.321: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  6 01:51:55.332: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgk44m5] to have phase Bound
Sep  6 01:51:55.342: INFO: PersistentVolumeClaim cinder.csi.openstack.orgk44m5 found but phase is Pending instead of Bound.
Sep  6 01:51:57.347: INFO: PersistentVolumeClaim cinder.csi.openstack.orgk44m5 found and phase=Bound (2.015365636s)
STEP: Creating pod pod-subpath-test-dynamicpv-fkc8
STEP: Creating a pod to test subpath
Sep  6 01:51:57.360: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-fkc8" in namespace "provisioning-3823" to be "Succeeded or Failed"
Sep  6 01:51:57.364: INFO: Pod "pod-subpath-test-dynamicpv-fkc8": Phase="Pending", Reason="", readiness=false. Elapsed: 3.211765ms
Sep  6 01:51:59.370: INFO: Pod "pod-subpath-test-dynamicpv-fkc8": Phase="Pending", Reason="", readiness=false. Elapsed: 2.009277559s
Sep  6 01:52:01.374: INFO: Pod "pod-subpath-test-dynamicpv-fkc8": Phase="Pending", Reason="", readiness=false. Elapsed: 4.013693486s
Sep  6 01:52:03.379: INFO: Pod "pod-subpath-test-dynamicpv-fkc8": Phase="Pending", Reason="", readiness=false. Elapsed: 6.019047956s
Sep  6 01:52:05.385: INFO: Pod "pod-subpath-test-dynamicpv-fkc8": Phase="Pending", Reason="", readiness=false. Elapsed: 8.024631401s
Sep  6 01:52:07.393: INFO: Pod "pod-subpath-test-dynamicpv-fkc8": Phase="Pending", Reason="", readiness=false. Elapsed: 10.032306203s
Sep  6 01:52:09.398: INFO: Pod "pod-subpath-test-dynamicpv-fkc8": Phase="Pending", Reason="", readiness=false. Elapsed: 12.037722348s
Sep  6 01:52:11.409: INFO: Pod "pod-subpath-test-dynamicpv-fkc8": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.048506426s
STEP: Saw pod success
Sep  6 01:52:11.409: INFO: Pod "pod-subpath-test-dynamicpv-fkc8" satisfied condition "Succeeded or Failed"
Sep  6 01:52:11.423: INFO: Trying to get logs from node k3s-master pod pod-subpath-test-dynamicpv-fkc8 container test-container-subpath-dynamicpv-fkc8: <nil>
STEP: delete the pod
Sep  6 01:52:11.449: INFO: Waiting for pod pod-subpath-test-dynamicpv-fkc8 to disappear
Sep  6 01:52:11.452: INFO: Pod pod-subpath-test-dynamicpv-fkc8 no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-fkc8
Sep  6 01:52:11.452: INFO: Deleting pod "pod-subpath-test-dynamicpv-fkc8" in namespace "provisioning-3823"
STEP: Creating pod pod-subpath-test-dynamicpv-fkc8
STEP: Creating a pod to test subpath
Sep  6 01:52:11.479: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-fkc8" in namespace "provisioning-3823" to be "Succeeded or Failed"
Sep  6 01:52:11.493: INFO: Pod "pod-subpath-test-dynamicpv-fkc8": Phase="Pending", Reason="", readiness=false. Elapsed: 13.646507ms
Sep  6 01:52:13.497: INFO: Pod "pod-subpath-test-dynamicpv-fkc8": Phase="Pending", Reason="", readiness=false. Elapsed: 2.017992313s
Sep  6 01:52:15.502: INFO: Pod "pod-subpath-test-dynamicpv-fkc8": Phase="Pending", Reason="", readiness=false. Elapsed: 4.02225703s
Sep  6 01:52:17.509: INFO: Pod "pod-subpath-test-dynamicpv-fkc8": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.029610773s
STEP: Saw pod success
Sep  6 01:52:17.509: INFO: Pod "pod-subpath-test-dynamicpv-fkc8" satisfied condition "Succeeded or Failed"
Sep  6 01:52:17.513: INFO: Trying to get logs from node k3s-master pod pod-subpath-test-dynamicpv-fkc8 container test-container-subpath-dynamicpv-fkc8: <nil>
STEP: delete the pod
Sep  6 01:52:17.542: INFO: Waiting for pod pod-subpath-test-dynamicpv-fkc8 to disappear
Sep  6 01:52:17.548: INFO: Pod pod-subpath-test-dynamicpv-fkc8 no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-fkc8
Sep  6 01:52:17.548: INFO: Deleting pod "pod-subpath-test-dynamicpv-fkc8" in namespace "provisioning-3823"
... skipping 18 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should support existing directories when readOnly specified in the volumeSource
    test/e2e/storage/testsuites/subpath.go:397
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath should support existing directories when readOnly specified in the volumeSource","total":244,"completed":73,"skipped":6234,"failed":0}
SSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral 
  should create read/write inline ephemeral volume
  test/e2e/storage/testsuites/ephemeral.go:196
[BeforeEach] [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral
... skipping 37 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral
  test/e2e/storage/framework/testsuite.go:50
    should create read/write inline ephemeral volume
    test/e2e/storage/testsuites/ephemeral.go:196
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Generic Ephemeral-volume (default fs) (immediate-binding)] ephemeral should create read/write inline ephemeral volume","total":244,"completed":74,"skipped":6237,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow] 
  should access to two volumes with different volume mode and retain data across pod recreation on the same node
  test/e2e/storage/testsuites/multivolume.go:209
[BeforeEach] [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow]
... skipping 179 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should access to two volumes with different volume mode and retain data across pod recreation on the same node
    test/e2e/storage/testsuites/multivolume.go:209
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow] should access to two volumes with different volume mode and retain data across pod recreation on the same node","total":244,"completed":75,"skipped":6291,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (filesystem volmode)] volumeMode 
  should not mount / map unused volumes in a pod [LinuxOnly]
  test/e2e/storage/testsuites/volumemode.go:354
[BeforeEach] [Testpattern: Pre-provisioned PV (filesystem volmode)] volumeMode
... skipping 84 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral
  test/e2e/storage/framework/testsuite.go:50
    should create read-only inline ephemeral volume
    test/e2e/storage/testsuites/ephemeral.go:175
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral should create read-only inline ephemeral volume","total":244,"completed":76,"skipped":6375,"failed":0}
SSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (delayed binding)] topology 
  should fail to schedule a pod which has topologies that conflict with AllowedTopologies
  test/e2e/storage/testsuites/topology.go:194
[BeforeEach] [Testpattern: Dynamic PV (delayed binding)] topology
  test/e2e/storage/framework/testsuite.go:51
[BeforeEach] [Testpattern: Dynamic PV (delayed binding)] topology
  test/e2e/framework/framework.go:187
STEP: Creating a kubernetes client
Sep  6 01:55:47.896: INFO: >>> kubeConfig: /root/.kube/config
STEP: Building a namespace api object, basename topology
STEP: Waiting for a default service account to be provisioned in namespace
STEP: Waiting for kube-root-ca.crt to be provisioned in namespace
[It] should fail to schedule a pod which has topologies that conflict with AllowedTopologies
  test/e2e/storage/testsuites/topology.go:194
Sep  6 01:55:47.945: INFO: found topology map[topology.cinder.csi.openstack.org/zone:nova]
Sep  6 01:55:47.945: INFO: Not enough topologies in cluster -- skipping
STEP: Deleting pvc
STEP: Deleting sc
[AfterEach] [Testpattern: Dynamic PV (delayed binding)] topology
... skipping 3 lines ...

S [SKIPPING] [0.069 seconds]
External Storage [Driver: cinder.csi.openstack.org]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (delayed binding)] topology
  test/e2e/storage/framework/testsuite.go:50
    should fail to schedule a pod which has topologies that conflict with AllowedTopologies [It]
    test/e2e/storage/testsuites/topology.go:194

    Not enough topologies in cluster -- skipping

    test/e2e/storage/testsuites/topology.go:201
------------------------------
... skipping 145 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy
  test/e2e/storage/framework/testsuite.go:50
    (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed via chgrp in first pod, new pod with different fsgroup applied to the volume contents
    test/e2e/storage/testsuites/fsgroupchangepolicy.go:216
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] fsgroupchangepolicy (OnRootMismatch)[LinuxOnly], pod created with an initial fsgroup, volume contents ownership changed via chgrp in first pod, new pod with different fsgroup applied to the volume contents","total":244,"completed":77,"skipped":6402,"failed":0}
SSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] volume-expand 
  should not allow expansion of pvcs without AllowVolumeExpansion property
  test/e2e/storage/testsuites/volume_expand.go:159
[BeforeEach] [Testpattern: Dynamic PV (default fs)] volume-expand
... skipping 14 lines ...
Sep  6 01:56:33.474: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  6 01:56:33.485: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgq7g9f] to have phase Bound
Sep  6 01:56:33.493: INFO: PersistentVolumeClaim cinder.csi.openstack.orgq7g9f found but phase is Pending instead of Bound.
Sep  6 01:56:35.499: INFO: PersistentVolumeClaim cinder.csi.openstack.orgq7g9f found and phase=Bound (2.013066237s)
STEP: Expanding non-expandable pvc
Sep  6 01:56:35.506: INFO: currentPvcSize {{1073741824 0} {<nil>} 1Gi BinarySI}, newSize {{2147483648 0} {<nil>}  BinarySI}
Sep  6 01:56:35.518: INFO: Error updating pvc cinder.csi.openstack.orgq7g9f: persistentvolumeclaims "cinder.csi.openstack.orgq7g9f" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:56:37.526: INFO: Error updating pvc cinder.csi.openstack.orgq7g9f: persistentvolumeclaims "cinder.csi.openstack.orgq7g9f" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:56:39.531: INFO: Error updating pvc cinder.csi.openstack.orgq7g9f: persistentvolumeclaims "cinder.csi.openstack.orgq7g9f" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:56:41.527: INFO: Error updating pvc cinder.csi.openstack.orgq7g9f: persistentvolumeclaims "cinder.csi.openstack.orgq7g9f" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:56:43.532: INFO: Error updating pvc cinder.csi.openstack.orgq7g9f: persistentvolumeclaims "cinder.csi.openstack.orgq7g9f" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:56:45.533: INFO: Error updating pvc cinder.csi.openstack.orgq7g9f: persistentvolumeclaims "cinder.csi.openstack.orgq7g9f" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:56:47.529: INFO: Error updating pvc cinder.csi.openstack.orgq7g9f: persistentvolumeclaims "cinder.csi.openstack.orgq7g9f" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:56:49.528: INFO: Error updating pvc cinder.csi.openstack.orgq7g9f: persistentvolumeclaims "cinder.csi.openstack.orgq7g9f" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:56:51.529: INFO: Error updating pvc cinder.csi.openstack.orgq7g9f: persistentvolumeclaims "cinder.csi.openstack.orgq7g9f" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:56:53.533: INFO: Error updating pvc cinder.csi.openstack.orgq7g9f: persistentvolumeclaims "cinder.csi.openstack.orgq7g9f" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:56:55.528: INFO: Error updating pvc cinder.csi.openstack.orgq7g9f: persistentvolumeclaims "cinder.csi.openstack.orgq7g9f" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:56:57.531: INFO: Error updating pvc cinder.csi.openstack.orgq7g9f: persistentvolumeclaims "cinder.csi.openstack.orgq7g9f" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:56:59.527: INFO: Error updating pvc cinder.csi.openstack.orgq7g9f: persistentvolumeclaims "cinder.csi.openstack.orgq7g9f" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:57:01.529: INFO: Error updating pvc cinder.csi.openstack.orgq7g9f: persistentvolumeclaims "cinder.csi.openstack.orgq7g9f" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:57:03.531: INFO: Error updating pvc cinder.csi.openstack.orgq7g9f: persistentvolumeclaims "cinder.csi.openstack.orgq7g9f" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:57:05.528: INFO: Error updating pvc cinder.csi.openstack.orgq7g9f: persistentvolumeclaims "cinder.csi.openstack.orgq7g9f" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  6 01:57:05.540: INFO: Error updating pvc cinder.csi.openstack.orgq7g9f: persistentvolumeclaims "cinder.csi.openstack.orgq7g9f" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
STEP: Deleting pvc
Sep  6 01:57:05.540: INFO: Deleting PersistentVolumeClaim "cinder.csi.openstack.orgq7g9f"
Sep  6 01:57:05.549: INFO: Waiting up to 5m0s for PersistentVolume pvc-6e9e1209-09ee-4a11-8b17-6dae5a6d5979 to get deleted
Sep  6 01:57:05.552: INFO: PersistentVolume pvc-6e9e1209-09ee-4a11-8b17-6dae5a6d5979 found and phase=Bound (3.762756ms)
Sep  6 01:57:10.557: INFO: PersistentVolume pvc-6e9e1209-09ee-4a11-8b17-6dae5a6d5979 was removed
STEP: Deleting sc
... skipping 7 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] volume-expand
  test/e2e/storage/framework/testsuite.go:50
    should not allow expansion of pvcs without AllowVolumeExpansion property
    test/e2e/storage/testsuites/volume_expand.go:159
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] volume-expand should not allow expansion of pvcs without AllowVolumeExpansion property","total":244,"completed":78,"skipped":6423,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Inline-volume (default fs)] subPath 
  should support existing single file [LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:221
[BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
... skipping 157 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (ext3)] volumes
  test/e2e/storage/framework/testsuite.go:50
    should store data
    test/e2e/storage/testsuites/volumes.go:161
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ext3)] volumes should store data","total":244,"completed":79,"skipped":6537,"failed":0}
SSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (immediate binding)] topology 
  should provision a volume and schedule a pod with AllowedTopologies
  test/e2e/storage/testsuites/topology.go:166
[BeforeEach] [Testpattern: Dynamic PV (immediate binding)] topology
... skipping 35 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (immediate binding)] topology
  test/e2e/storage/framework/testsuite.go:50
    should provision a volume and schedule a pod with AllowedTopologies
    test/e2e/storage/testsuites/topology.go:166
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (immediate binding)] topology should provision a volume and schedule a pod with AllowedTopologies","total":244,"completed":80,"skipped":6544,"failed":0}
SSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic Snapshot (retain policy)] snapshottable-stress[Feature:VolumeSnapshotDataSource] 
  should support snapshotting of many volumes repeatedly [Slow] [Serial]
  test/e2e/storage/testsuites/snapshottable_stress.go:259
[BeforeEach] [Testpattern: Dynamic Snapshot (retain policy)] snapshottable-stress[Feature:VolumeSnapshotDataSource]
... skipping 224 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should access to two volumes with the same volume mode and retain data across pod recreation on the same node
    test/e2e/storage/testsuites/multivolume.go:138
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow] should access to two volumes with the same volume mode and retain data across pod recreation on the same node","total":244,"completed":81,"skipped":6597,"failed":0}
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (default fs)] subPath 
  should support non-existent path
  test/e2e/storage/testsuites/subpath.go:196
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
Sep  6 01:59:23.569: INFO: Driver "cinder.csi.openstack.org" does not support volume type "PreprovisionedPV" - skipping
... skipping 85 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] volumeIO
  test/e2e/storage/framework/testsuite.go:50
    should write files of various sizes, verify size, validate content [Slow]
    test/e2e/storage/testsuites/volume_io.go:149
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] volumeIO should write files of various sizes, verify size, validate content [Slow]","total":244,"completed":82,"skipped":6648,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath 
  should be able to unmount after the subpath directory is deleted [LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:447
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
... skipping 12 lines ...

    Driver cinder.csi.openstack.org doesn't support ntfs -- skipping

    test/e2e/storage/framework/testsuite.go:121
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (default fs)] subPath 
  should fail if subpath file is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:258
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:51
Sep  6 02:00:06.826: INFO: Driver "cinder.csi.openstack.org" does not support volume type "PreprovisionedPV" - skipping
[AfterEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/framework/framework.go:188

S [SKIPPING] in Spec Setup (BeforeEach) [0.000 seconds]
External Storage [Driver: cinder.csi.openstack.org]
test/e2e/storage/external/external.go:174
  [Testpattern: Pre-provisioned PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath file is outside the volume [Slow][LinuxOnly] [BeforeEach]
    test/e2e/storage/testsuites/subpath.go:258

    Driver "cinder.csi.openstack.org" does not support volume type "PreprovisionedPV" - skipping

    test/e2e/storage/external/external.go:262
------------------------------
... skipping 20 lines ...
Sep  6 02:00:06.879: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  6 02:00:06.888: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgtlnc9] to have phase Bound
Sep  6 02:00:06.899: INFO: PersistentVolumeClaim cinder.csi.openstack.orgtlnc9 found but phase is Pending instead of Bound.
Sep  6 02:00:08.903: INFO: PersistentVolumeClaim cinder.csi.openstack.orgtlnc9 found and phase=Bound (2.014326296s)
STEP: Creating pod pod-subpath-test-dynamicpv-wzvh
STEP: Creating a pod to test subpath
Sep  6 02:00:08.916: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-wzvh" in namespace "provisioning-9371" to be "Succeeded or Failed"
Sep  6 02:00:08.923: INFO: Pod "pod-subpath-test-dynamicpv-wzvh": Phase="Pending", Reason="", readiness=false. Elapsed: 6.934534ms
Sep  6 02:00:10.928: INFO: Pod "pod-subpath-test-dynamicpv-wzvh": Phase="Pending", Reason="", readiness=false. Elapsed: 2.01237913s
Sep  6 02:00:12.935: INFO: Pod "pod-subpath-test-dynamicpv-wzvh": Phase="Pending", Reason="", readiness=false. Elapsed: 4.018973936s
Sep  6 02:00:14.941: INFO: Pod "pod-subpath-test-dynamicpv-wzvh": Phase="Pending", Reason="", readiness=false. Elapsed: 6.024759298s
Sep  6 02:00:16.950: INFO: Pod "pod-subpath-test-dynamicpv-wzvh": Phase="Pending", Reason="", readiness=false. Elapsed: 8.033505653s
Sep  6 02:00:18.955: INFO: Pod "pod-subpath-test-dynamicpv-wzvh": Phase="Pending", Reason="", readiness=false. Elapsed: 10.0385396s
Sep  6 02:00:20.963: INFO: Pod "pod-subpath-test-dynamicpv-wzvh": Phase="Pending", Reason="", readiness=false. Elapsed: 12.047400066s
Sep  6 02:00:22.967: INFO: Pod "pod-subpath-test-dynamicpv-wzvh": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.051326179s
STEP: Saw pod success
Sep  6 02:00:22.967: INFO: Pod "pod-subpath-test-dynamicpv-wzvh" satisfied condition "Succeeded or Failed"
Sep  6 02:00:22.971: INFO: Trying to get logs from node k3s-master pod pod-subpath-test-dynamicpv-wzvh container test-container-volume-dynamicpv-wzvh: <nil>
STEP: delete the pod
Sep  6 02:00:23.010: INFO: Waiting for pod pod-subpath-test-dynamicpv-wzvh to disappear
Sep  6 02:00:23.019: INFO: Pod pod-subpath-test-dynamicpv-wzvh no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-wzvh
Sep  6 02:00:23.019: INFO: Deleting pod "pod-subpath-test-dynamicpv-wzvh" in namespace "provisioning-9371"
... skipping 16 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (default fs)] subPath
  test/e2e/storage/framework/testsuite.go:50
    should support non-existent path
    test/e2e/storage/testsuites/subpath.go:196
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath should support non-existent path","total":244,"completed":83,"skipped":6687,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (filesystem volmode)] multiVolume [Slow] 
  should concurrently access the single read-only volume from pods on the same node
  test/e2e/storage/testsuites/multivolume.go:423
[BeforeEach] [Testpattern: Pre-provisioned PV (filesystem volmode)] multiVolume [Slow]
... skipping 120 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should concurrently access the single read-only volume from pods on the same node
    test/e2e/storage/testsuites/multivolume.go:423
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow] should concurrently access the single read-only volume from pods on the same node","total":244,"completed":84,"skipped":6738,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (block volmode)] provisioning 
  should mount multiple PV pointing to the same storage on the same node
  test/e2e/storage/testsuites/provisioning.go:518
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] provisioning
... skipping 94 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral
  test/e2e/storage/framework/testsuite.go:50
    should support multiple inline ephemeral volumes
    test/e2e/storage/testsuites/ephemeral.go:254
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Generic Ephemeral-volume (default fs) (late-binding)] ephemeral should support multiple inline ephemeral volumes","total":244,"completed":85,"skipped":6855,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath 
  should fail if non-existent subpath is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:269
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  test/e2e/storage/framework/testsuite.go:51
Sep  6 02:02:33.351: INFO: Driver cinder.csi.openstack.org doesn't support ntfs -- skipping
[AfterEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  test/e2e/framework/framework.go:188

S [SKIPPING] in Spec Setup (BeforeEach) [0.001 seconds]
External Storage [Driver: cinder.csi.openstack.org]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if non-existent subpath is outside the volume [Slow][LinuxOnly] [BeforeEach]
    test/e2e/storage/testsuites/subpath.go:269

    Driver cinder.csi.openstack.org doesn't support ntfs -- skipping

    test/e2e/storage/framework/testsuite.go:121
------------------------------
... skipping 20 lines ...
Sep  6 02:02:33.429: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  6 02:02:33.446: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.org9mvwz] to have phase Bound
Sep  6 02:02:33.453: INFO: PersistentVolumeClaim cinder.csi.openstack.org9mvwz found but phase is Pending instead of Bound.
Sep  6 02:02:35.457: INFO: PersistentVolumeClaim cinder.csi.openstack.org9mvwz found and phase=Bound (2.010804798s)
STEP: Creating pod exec-volume-test-dynamicpv-nwhs
STEP: Creating a pod to test exec-volume-test
Sep  6 02:02:35.493: INFO: Waiting up to 5m0s for pod "exec-volume-test-dynamicpv-nwhs" in namespace "volume-3376" to be "Succeeded or Failed"
Sep  6 02:02:35.499: INFO: Pod "exec-volume-test-dynamicpv-nwhs": Phase="Pending", Reason="", readiness=false. Elapsed: 5.856951ms
Sep  6 02:02:37.505: INFO: Pod "exec-volume-test-dynamicpv-nwhs": Phase="Pending", Reason="", readiness=false. Elapsed: 2.011764069s
Sep  6 02:02:39.516: INFO: Pod "exec-volume-test-dynamicpv-nwhs": Phase="Pending", Reason="", readiness=false. Elapsed: 4.022543223s
Sep  6 02:02:41.521: INFO: Pod "exec-volume-test-dynamicpv-nwhs": Phase="Pending", Reason="", readiness=false. Elapsed: 6.027113977s
Sep  6 02:02:43.529: INFO: Pod "exec-volume-test-dynamicpv-nwhs": Phase="Pending", Reason="", readiness=false. Elapsed: 8.036046934s
Sep  6 02:02:45.534: INFO: Pod "exec-volume-test-dynamicpv-nwhs": Phase="Pending", Reason="", readiness=false. Elapsed: 10.040524955s
Sep  6 02:02:47.539: INFO: Pod "exec-volume-test-dynamicpv-nwhs": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.045729015s
STEP: Saw pod success
Sep  6 02:02:47.539: INFO: Pod "exec-volume-test-dynamicpv-nwhs" satisfied condition "Succeeded or Failed"
Sep  6 02:02:47.543: INFO: Trying to get logs from node k3s-master pod exec-volume-test-dynamicpv-nwhs container exec-container-dynamicpv-nwhs: <nil>
STEP: delete the pod
Sep  6 02:02:47.563: INFO: Waiting for pod exec-volume-test-dynamicpv-nwhs to disappear
Sep  6 02:02:47.568: INFO: Pod exec-volume-test-dynamicpv-nwhs no longer exists
STEP: Deleting pod exec-volume-test-dynamicpv-nwhs
Sep  6 02:02:47.568: INFO: Deleting pod "exec-volume-test-dynamicpv-nwhs" in namespace "volume-3376"
... skipping 13 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (ext4)] volumes
  test/e2e/storage/framework/testsuite.go:50
    should allow exec of files on the volume
    test/e2e/storage/testsuites/volumes.go:198
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ext4)] volumes should allow exec of files on the volume","total":244,"completed":86,"skipped":6999,"failed":0}
SSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Inline-volume (ext4)] volumes 
  should store data
  test/e2e/storage/testsuites/volumes.go:161
[BeforeEach] [Testpattern: Inline-volume (ext4)] volumes
... skipping 37 lines ...

    test/e2e/storage/framework/testsuite.go:121
------------------------------
SSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath 
  should fail if subpath directory is outside the volume [Slow][LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:242
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  test/e2e/storage/framework/testsuite.go:51
Sep  6 02:02:52.613: INFO: Driver cinder.csi.openstack.org doesn't support ntfs -- skipping
[AfterEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  test/e2e/framework/framework.go:188

S [SKIPPING] in Spec Setup (BeforeEach) [0.000 seconds]
External Storage [Driver: cinder.csi.openstack.org]
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
  test/e2e/storage/framework/testsuite.go:50
    should fail if subpath directory is outside the volume [Slow][LinuxOnly] [BeforeEach]
    test/e2e/storage/testsuites/subpath.go:242

    Driver cinder.csi.openstack.org doesn't support ntfs -- skipping

    test/e2e/storage/framework/testsuite.go:121
------------------------------
... skipping 77 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should concurrently access the volume and its clone from pods on the same node [LinuxOnly][Feature:VolumeSnapshotDataSource][Feature:VolumeSourceXFS]
    test/e2e/storage/testsuites/multivolume.go:378
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow] should concurrently access the volume and its clone from pods on the same node [LinuxOnly][Feature:VolumeSnapshotDataSource][Feature:VolumeSourceXFS]","total":244,"completed":87,"skipped":7099,"failed":0}
SSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow] 
  should concurrently access the volume and restored snapshot from pods on the same node [LinuxOnly][Feature:VolumeSnapshotDataSource][Feature:VolumeSourceXFS]
  test/e2e/storage/testsuites/multivolume.go:323
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow]
... skipping 157 lines ...
test/e2e/storage/external/external.go:174
  [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:50
    should concurrently access the volume and restored snapshot from pods on the same node [LinuxOnly][Feature:VolumeSnapshotDataSource][Feature:VolumeSourceXFS]
    test/e2e/storage/testsuites/multivolume.go:323
------------------------------
{"msg":"PASSED External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow] should concurrently access the volume and restored snapshot from pods on the same node [LinuxOnly][Feature:VolumeSnapshotDataSource][Feature:VolumeSourceXFS]","total":244,"completed":88,"skipped":7104,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSep  6 02:06:55.466: INFO: Running AfterSuite actions on all nodes
Sep  6 02:06:55.466: INFO: Running Cleanup Action: k8s.io/kubernetes/test/e2e/storage.glob..func19.2
Sep  6 02:06:55.466: INFO: Running Cleanup Action: k8s.io/kubernetes/test/e2e/storage.glob..func9.2
Sep  6 02:06:55.466: INFO: Running Cleanup Action: k8s.io/kubernetes/test/e2e/storage.glob..func8.2
Sep  6 02:06:55.466: INFO: Running Cleanup Action: k8s.io/kubernetes/test/e2e/storage/vsphere.glob..func17.3
Sep  6 02:06:55.466: INFO: Running Cleanup Action: k8s.io/kubernetes/test/e2e/storage/vsphere.glob..func9.2
Sep  6 02:06:55.466: INFO: Running Cleanup Action: k8s.io/kubernetes/test/e2e/storage/vsphere.glob..func4.2
Sep  6 02:06:55.466: INFO: Running Cleanup Action: k8s.io/kubernetes/test/e2e/storage/vsphere.glob..func1.3
Sep  6 02:06:55.466: INFO: Running AfterSuite actions on node 1
Sep  6 02:06:55.466: INFO: Dumping logs locally to: /var/log/csi-pod
Sep  6 02:06:55.466: INFO: Error running cluster/log-dump/log-dump.sh: fork/exec ../../cluster/log-dump/log-dump.sh: no such file or directory

JUnit report was created: /var/log/csi-pod/junit_01.xml
{"msg":"Test Suite completed","total":244,"completed":88,"skipped":7139,"failed":0}

Ran 88 of 7227 Specs in 4961.907 seconds
SUCCESS! -- 88 Passed | 0 Failed | 0 Pending | 7139 Skipped
PASS


STDERR:

+ set -e
... skipping 18 lines ...
STDERR:

+ set -e
+ kubectl logs deployment/csi-cinder-controllerplugin -n kube-system -c cinder-csi-plugin
+ kubectl logs daemonset/csi-cinder-nodeplugin -n kube-system -c cinder-csi-plugin

TASK [install-csi-cinder : fail] ***********************************************
skipping: [34.150.148.63] => {
    "changed": false,
    "skip_reason": "Conditional result was False"
}

RUNNING HANDLER [install-docker : Restart Docker] ******************************
... skipping 244 lines ...
        "WatchdogTimestampMonotonic": "0",
        "WatchdogUSec": "0"
    }
}

PLAY RECAP *********************************************************************
34.150.148.63              : ok=61   changed=51   unreachable=0    failed=0    skipped=11   rescued=0    ignored=1   

+ exit_code=0
+ scp -i /root/.ssh/google_compute_engine -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -r 'root@34.150.148.63:/var/log/csi-pod/*' /logs/artifacts/logs/
Warning: Permanently added '34.150.148.63' (ECDSA) to the list of known hosts.
+ '[' -z boskos.test-pods.svc.cluster.local ']'
+ python3 tests/scripts/boskos.py --release
... skipping 13 lines ...