This job view page is being replaced by Spyglass soon. Check out the new job view.
PRjichenjc: cherry pick support mounting btrfs volumes by the cinder-csi-plugin (#1941) to 1.24
Resultsuccess
Tests 0 failed / 0 succeeded
Started2022-09-05 06:12
Elapsed1h40m
Revision
Refs 1944
uploadercrier
uploadercrier

No Test Failures!


Error lines from build-log.txt

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

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

TASK [install-golang : Check if go has satisfied requirement] ******************
fatal: [34.145.133.94]: FAILED! => {
    "changed": true,
    "cmd": "/usr/local/go/bin/go version |grep -Eo '([0-9]+\\.)+[0-9]+'",
    "delta": "0:00:00.003529",
    "end": "2022-09-05 06:18:03.206212",
    "rc": 1,
    "start": "2022-09-05 06:18:03.202683"
... skipping 2585 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.5 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=6f3e889c5b942ba09bcdafea7006bd136ae029aab839b659af06151ad763dcd0
  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 attrs===21.2.0
  Downloading attrs-21.2.0-py2.py3-none-any.whl (53 kB)
Collecting pyperclip===1.8.2
  Downloading pyperclip-1.8.2.tar.gz (20 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-1k3hnrqk/prettytable/setup.py'"'"'; __file__='"'"'/tmp/pip-install-1k3hnrqk/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-gcsqo3rg
       cwd: /tmp/pip-install-1k3hnrqk/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-1k3hnrqk/pyperclip/setup.py'"'"'; __file__='"'"'/tmp/pip-install-1k3hnrqk/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-a1276qtd
       cwd: /tmp/pip-install-1k3hnrqk/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-fs7pfg1b/setup.py'"'"'; __file__='"'"'/tmp/pip-req-build-fs7pfg1b/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-_hhimm6b
       cwd: /tmp/pip-req-build-fs7pfg1b/
  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, six, extras, testtools, fixtures, wcwidth, prettytable, urllib3, PyYAML, idna, charset-normalizer, requests, stevedore, autopage, pyparsing, colorama, pyperclip, cmd2, 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 28874
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 (964 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 ... 91508 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 Mon 2022-09-05 06:22:06 UTC; 8ms ago

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

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

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

Sep 05 06:22:06 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=eff4ec7144f9e41ef0f5d14e7efd137b4a5ca6c93815f0fe3b689c067b56e9ee
  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 ...
Collecting charset-normalizer~=2.0.0
  Downloading charset_normalizer-2.0.4-py3-none-any.whl (36 kB)
Collecting certifi>=2017.4.17
  Downloading certifi-2021.5.30-py2.py3-none-any.whl (145 kB)
     ━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━━ 145.5/145.5 kB 33.4 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=78575 sha256=a9d98448bc8572e90800c5bbf08e851e4d35957cdbe129ce7201aa60a72722a4
  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=20bf489899bc42caa12a922021dad239
++ functions-common:get_or_create_user:860  :   echo 20bf489899bc42caa12a922021dad239
+ lib/cinder:configure_cinder_internal_tenant:614 :   iniset /etc/cinder/cinder.conf DEFAULT cinder_internal_tenant_user_id 20bf489899bc42caa12a922021dad239
[8851 Async create_cinder_accounts:58314]: 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=63122) 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/tmpti6jrq3f/privsep.sock']
INFO oslo.privsep.daemon [-] Spawned new privsep daemon via rootwrap
DEBUG oslo.privsep.daemon [-] Accepted privsep connection to /tmp/tmpti6jrq3f/privsep.sock {{(pid=63122) __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 ...
             ├─69915 nova-apiuWSGI master
             ├─69916 nova-apiuWSGI worker 1
             └─69917 nova-apiuWSGI worker 2

Sep 05 06:30:43 devstack devstack@n-api.service[69916]: [pid: 69916|app: 0|req: 17/35] 10.0.2.15 () {64 vars in 1322 bytes} [Mon Sep  5 06:30:43 2022] POST /compute/v2.1/flavors/5/os-extra_specs => generated 43 bytes in 18 msecs (HTTP/1.1 200) 9 headers in 358 bytes (1 switches on core 0)
Sep 05 06:30:51 devstack devstack@n-api.service[69917]: DEBUG nova.api.openstack.wsgi [None req-273d6eb9-e5ec-4bce-a7f2-e1985ee17034 admin admin] Calling method '<bound method ServiceController.index of <nova.api.openstack.compute.services.ServiceController object at 0x7ff8c0668070>>' {{(pid=69917) _process_stack /opt/stack/nova/nova/api/openstack/wsgi.py:513}}
Sep 05 06:30:51 devstack devstack@n-api.service[69917]: /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 05 06:30:51 devstack devstack@n-api.service[69917]:   warnings.warn(msg)
Sep 05 06:30:51 devstack devstack@n-api.service[69917]: DEBUG oslo_concurrency.lockutils [None req-273d6eb9-e5ec-4bce-a7f2-e1985ee17034 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=69917) inner /usr/local/lib/python3.8/dist-packages/oslo_concurrency/lockutils.py:355}}
Sep 05 06:30:51 devstack devstack@n-api.service[69917]: DEBUG oslo_concurrency.lockutils [None req-273d6eb9-e5ec-4bce-a7f2-e1985ee17034 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=69917) inner /usr/local/lib/python3.8/dist-packages/oslo_concurrency/lockutils.py:367}}
Sep 05 06:30:51 devstack devstack@n-api.service[69917]: DEBUG oslo_concurrency.lockutils [None req-273d6eb9-e5ec-4bce-a7f2-e1985ee17034 admin admin] Lock "ad215eef-13e8-4996-bf4c-e051f3796aa1" acquired by "nova.context.set_target_cell.<locals>.get_or_set_cached_cell_and_set_connections" :: waited 0.000s {{(pid=69917) inner /usr/local/lib/python3.8/dist-packages/oslo_concurrency/lockutils.py:355}}
Sep 05 06:30:51 devstack devstack@n-api.service[69917]: DEBUG oslo_concurrency.lockutils [None req-273d6eb9-e5ec-4bce-a7f2-e1985ee17034 admin admin] Lock "ad215eef-13e8-4996-bf4c-e051f3796aa1" released by "nova.context.set_target_cell.<locals>.get_or_set_cached_cell_and_set_connections" :: held 0.000s {{(pid=69917) inner /usr/local/lib/python3.8/dist-packages/oslo_concurrency/lockutils.py:367}}
Sep 05 06:30:51 devstack devstack@n-api.service[69917]: INFO nova.api.openstack.requestlog [None req-273d6eb9-e5ec-4bce-a7f2-e1985ee17034 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.047441
... skipping 20 lines ...
Sep 05 06:30:32 devstack nova-compute[77202]: DEBUG oslo_concurrency.lockutils [None req-4fff39a5-9c6e-416c-b900-89e2fb04cdf6 None None] Lock "compute_resources" released by "nova.compute.resource_tracker.ResourceTracker._update_available_resource" :: held 0.336s {{(pid=77202) inner /usr/local/lib/python3.8/dist-packages/oslo_concurrency/lockutils.py:367}}
Sep 05 06:30:32 devstack nova-compute[77202]: DEBUG nova.service [None req-4fff39a5-9c6e-416c-b900-89e2fb04cdf6 None None] Creating RPC server for service compute {{(pid=77202) start /opt/stack/nova/nova/service.py:182}}
Sep 05 06:30:32 devstack nova-compute[77202]: DEBUG nova.service [None req-4fff39a5-9c6e-416c-b900-89e2fb04cdf6 None None] Join ServiceGroup membership for this service compute {{(pid=77202) start /opt/stack/nova/nova/service.py:199}}
Sep 05 06:30:32 devstack nova-compute[77202]: DEBUG nova.servicegroup.drivers.db [None req-4fff39a5-9c6e-416c-b900-89e2fb04cdf6 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=77202) 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 05 06:30:32 devstack devstack@placement-api.service[71121]: [pid: 71121|app: 0|req: 4/9] 10.0.2.15 () {60 vars in 3540 bytes} [Mon Sep  5 06:30:32 2022] GET /placement/traits?name=in:COMPUTE_GRAPHICS_MODEL_VGA,COMPUTE_NET_VIF_MODEL_SPAPR_VLAN,COMPUTE_NET_VIF_MODEL_PCNET,COMPUTE_NET_VIF_MODEL_E1000,COMPUTE_IMAGE_TYPE_AKI,HW_CPU_X86_SVM,COMPUTE_STORAGE_BUS_FDC,COMPUTE_GRAPHICS_MODEL_NONE,COMPUTE_GRAPHICS_MODEL_CIRRUS,COMPUTE_NET_VIF_MODEL_NE2K_PCI,COMPUTE_NET_VIF_MODEL_RTL8139,COMPUTE_IMAGE_TYPE_RAW,COMPUTE_VOLUME_MULTI_ATTACH,HW_CPU_X86_SSE,COMPUTE_IMAGE_TYPE_QCOW2,HW_CPU_X86_SSE2,COMPUTE_STORAGE_BUS_VIRTIO,COMPUTE_VOLUME_ATTACH_WITH_TAG,COMPUTE_RESCUE_BFV,COMPUTE_NET_VIF_MODEL_E1000E,HW_CPU_X86_AMD_SVM,COMPUTE_NODE,COMPUTE_GRAPHICS_MODEL_VMVGA,COMPUTE_IMAGE_TYPE_ARI,HW_CPU_X86_MMX,HW_CPU_HYPERTHREADING,COMPUTE_STORAGE_BUS_SCSI,COMPUTE_NET_ATTACH_INTERFACE_WITH_TAG,COMPUTE_SECURITY_UEFI_SECURE_BOOT,COMPUTE_NET_ATTACH_INTERFACE,COMPUTE_GRAPHICS_MODEL_BOCHS,COMPUTE_IMAGE_TYPE_AMI,COMPUTE_SOCKET_PCI_NUMA_AFFINITY,COMPUTE_STORAGE_BUS_SATA,COMPUTE_STORAGE_BUS_IDE,COMPUTE_IMAGE_TYPE_ISO,COMPUTE_TRUSTED_CERTS,COMPUTE_GRAPHICS_MODEL_VIRTIO,COMPUTE_NET_VIF_MODEL_VMXNET3,COMPUTE_NET_VIF_MODEL_VIRTIO,COMPUTE_VOLUME_EXTEND,COMPUTE_DEVICE_TAGGING,COMPUTE_STORAGE_BUS_USB,COMPUTE_GRAPHICS_MODEL_QXL,COMPUTE_ACCELERATORS => generated 1289 bytes in 9 msecs (HTTP/1.1 200) 6 headers in 225 bytes (1 switches on core 0)
Sep 05 06:30:32 devstack devstack@placement-api.service[71120]: DEBUG placement.requestlog [req-571a73b2-bf7a-4b9a-9761-a0ae435a8f49 req-027860e5-4f44-408e-adcf-626712cbc5e0 None None] Starting request: 10.0.2.15 "PUT /placement/resource_providers/36fa7879-554f-4525-813a-369988f52ffe/traits" {{(pid=71120) __call__ /opt/stack/placement/placement/requestlog.py:55}}
Sep 05 06:30:32 devstack devstack@placement-api.service[71120]: INFO placement.requestlog [req-571a73b2-bf7a-4b9a-9761-a0ae435a8f49 req-027860e5-4f44-408e-adcf-626712cbc5e0 service placement] 10.0.2.15 "PUT /placement/resource_providers/36fa7879-554f-4525-813a-369988f52ffe/traits" status: 200 len: 1324 microversion: 1.6
Sep 05 06:30:32 devstack devstack@placement-api.service[71120]: [pid: 71120|app: 0|req: 6/10] 10.0.2.15 () {64 vars in 1463 bytes} [Mon Sep  5 06:30:32 2022] PUT /placement/resource_providers/36fa7879-554f-4525-813a-369988f52ffe/traits => generated 1324 bytes in 52 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 05 06:30:41 devstack devstack@g-api.service[79713]: DEBUG glance_store._drivers.filesystem [None req-93f0b55d-884c-4bde-b8f6-9f5cbd3d301d admin admin] Wrote 16300544 bytes to /opt/stack/data/glance/images/e344777b-d166-4d8d-94eb-a9d6e6615c54 with checksum b874c39491a2377b8490f5f1e89761a4 and multihash 6b813aa46bb90b4da216a4d19376593fa3f4fc7e617f03a92b7fe11e9a3981cbe8f0959dbebe36225e5f53dc4492341a4863cac4ed1ee0909f3fc78ef9c3e869 {{(pid=79713) add /usr/local/lib/python3.8/dist-packages/glance_store/_drivers/filesystem.py:773}}
Sep 05 06:30:41 devstack devstack@g-api.service[79713]: INFO glance.location [None req-93f0b55d-884c-4bde-b8f6-9f5cbd3d301d admin admin] Image format matched and virtual size computed: 117440512
Sep 05 06:30:41 devstack devstack@g-api.service[79713]: DEBUG glance_store.backend [None req-93f0b55d-884c-4bde-b8f6-9f5cbd3d301d admin admin] Skipping store.set_acls... not implemented. {{(pid=79713) set_acls /usr/local/lib/python3.8/dist-packages/glance_store/backend.py:509}}
Sep 05 06:30:41 devstack devstack@g-api.service[79713]: [pid: 79713|app: 0|req: 3/4] 127.0.0.1 () {40 vars in 856 bytes} [Mon Sep  5 06:30:40 2022] PUT /v2/images/e344777b-d166-4d8d-94eb-a9d6e6615c54/file => generated 0 bytes in 922 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).
changed: [34.145.133.94] => {
    "attempts": 10,
    "changed": true,
    "cmd": "ssh -o UserKnownHostsFile=/dev/null -o StrictHostKeyChecking=no -i /root/.ssh/id_rsa ubuntu@172.24.5.176 sudo chmod 777 /etc/rancher/k3s/k3s.yaml\n",
    "delta": "0:00:00.866492",
    "end": "2022-09-05 06:33:41.839933",
... 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.176: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.145.133.94] => {
    "attempts": 2,
    "changed": true,
    "cmd": "kubectl --kubeconfig /root/.kube/config get node | grep \" Ready \" | wc -l\n",
    "delta": "0:00:00.064440",
    "end": "2022-09-05 06:33:55.554244",
... skipping 426 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.145.133.94] => {
    "attempts": 2,
    "changed": true,
    "cmd": "kubectl -n kube-system get pod | grep openstack-cloud-controller-manager | grep Running\n",
    "delta": "0:00:00.058875",
    "end": "2022-09-05 06:35:11.210654",
... skipping 2 lines ...
}

STDOUT:

openstack-cloud-controller-manager-cf5c8b77f-4vgf8   1/1     Running   0          7s

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

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

TASK [install-cpo-occm : Show openstack-cloud-controller-manager pod logs] *****
skipping: [34.145.133.94] => {
    "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.145.133.94] => {
    "attempts": 5,
    "changed": true,
    "cmd": "kubectl -n kube-system get pod | grep csi-cinder-controllerplugin  | grep Running\n",
    "delta": "0:00:00.063402",
    "end": "2022-09-05 06:36:48.911215",
... skipping 33 lines ...

STDOUT:

snapshot-controller-7f5d798964-4zsjt                 1/1     Running   0          26s
snapshot-controller-7f5d798964-t5r4k                 1/1     Running   0          26s

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

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

TASK [install-csi-cinder : Stop due to prior failure of csi-cinder-plugin] *****
skipping: [34.145.133.94] => {
    "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.145.133.94] => {
    "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:15:23.831253",
    "end": "2022-09-05 07:52:37.151952",
    "rc": 0,
    "start": "2022-09-05 06:37:13.320699"
}

STDOUT:

Sep  5 06:37:13.393: 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  5 06:37:13.393: 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: 1662359833 - Will randomize all specs
Will run 244 of 7233 specs

Sep  5 06:37:14.859: INFO: >>> kubeConfig: /root/.kube/config
... skipping 153 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":1,"skipped":81,"failed":0}
SSSSS
------------------------------
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":2,"skipped":86,"failed":0}
SSSSSSSSSSSSSS
------------------------------
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)
  test/e2e/storage/testsuites/snapshottable.go:278
[BeforeEach] [Testpattern: Dynamic Snapshot (delete policy)] snapshottable[Feature:VolumeSnapshotDataSource]
... skipping 14 lines ...
Sep  5 06:39:09.033: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  5 06:39:09.045: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgdl49h] to have phase Bound
Sep  5 06:39:09.061: INFO: PersistentVolumeClaim cinder.csi.openstack.orgdl49h found but phase is Pending instead of Bound.
Sep  5 06:39:11.066: INFO: PersistentVolumeClaim cinder.csi.openstack.orgdl49h found and phase=Bound (2.020132752s)
STEP: [init] starting a pod to use the claim
STEP: [init] check pod success
Sep  5 06:39:11.079: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-w28cf" in namespace "snapshotting-6495" to be "Succeeded or Failed"
Sep  5 06:39:11.084: INFO: Pod "pvc-snapshottable-tester-w28cf": Phase="Pending", Reason="", readiness=false. Elapsed: 4.259332ms
Sep  5 06:39:13.088: INFO: Pod "pvc-snapshottable-tester-w28cf": Phase="Pending", Reason="", readiness=false. Elapsed: 2.009059529s
Sep  5 06:39:15.093: INFO: Pod "pvc-snapshottable-tester-w28cf": Phase="Pending", Reason="", readiness=false. Elapsed: 4.013745071s
Sep  5 06:39:17.098: INFO: Pod "pvc-snapshottable-tester-w28cf": Phase="Pending", Reason="", readiness=false. Elapsed: 6.018930543s
Sep  5 06:39:19.103: INFO: Pod "pvc-snapshottable-tester-w28cf": Phase="Pending", Reason="", readiness=false. Elapsed: 8.02401422s
Sep  5 06:39:21.111: INFO: Pod "pvc-snapshottable-tester-w28cf": Phase="Pending", Reason="", readiness=false. Elapsed: 10.032028192s
Sep  5 06:39:23.117: INFO: Pod "pvc-snapshottable-tester-w28cf": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.03715107s
STEP: Saw pod success
Sep  5 06:39:23.117: INFO: Pod "pvc-snapshottable-tester-w28cf" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
Sep  5 06:39:23.119: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgdl49h] to have phase Bound
Sep  5 06:39:23.122: INFO: PersistentVolumeClaim cinder.csi.openstack.orgdl49h found and phase=Bound (2.372978ms)
STEP: [init] checking the PV
STEP: [init] deleting the pod
Sep  5 06:39:23.137: INFO: Pod pvc-snapshottable-tester-w28cf has the following logs: 
... skipping 12 lines ...
Sep  5 06:39:27.209: INFO: received snapshotStatus map[boundVolumeSnapshotContentName:snapcontent-d847cd44-2ea8-4f24-9b81-4da7664f7fb2 creationTime:2022-09-05T06:39:24Z readyToUse:true restoreSize:1Gi]
Sep  5 06:39:27.209: INFO: snapshotContentName snapcontent-d847cd44-2ea8-4f24-9b81-4da7664f7fb2
STEP: checking the snapshot
STEP: checking the SnapshotContent
STEP: Modifying source data test
STEP: modifying the data in the source PVC
Sep  5 06:39:27.222: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-data-tester-xbkgf" in namespace "snapshotting-6495" to be "Succeeded or Failed"
Sep  5 06:39:27.229: INFO: Pod "pvc-snapshottable-data-tester-xbkgf": Phase="Pending", Reason="", readiness=false. Elapsed: 7.526985ms
Sep  5 06:39:29.234: INFO: Pod "pvc-snapshottable-data-tester-xbkgf": Phase="Pending", Reason="", readiness=false. Elapsed: 2.012178798s
Sep  5 06:39:31.239: INFO: Pod "pvc-snapshottable-data-tester-xbkgf": Phase="Pending", Reason="", readiness=false. Elapsed: 4.017668272s
Sep  5 06:39:33.246: INFO: Pod "pvc-snapshottable-data-tester-xbkgf": Phase="Pending", Reason="", readiness=false. Elapsed: 6.02380343s
Sep  5 06:39:35.250: INFO: Pod "pvc-snapshottable-data-tester-xbkgf": Phase="Pending", Reason="", readiness=false. Elapsed: 8.027912649s
Sep  5 06:39:37.254: INFO: Pod "pvc-snapshottable-data-tester-xbkgf": Phase="Succeeded", Reason="", readiness=false. Elapsed: 10.031957815s
STEP: Saw pod success
Sep  5 06:39:37.254: INFO: Pod "pvc-snapshottable-data-tester-xbkgf" satisfied condition "Succeeded or Failed"
Sep  5 06:39:37.266: INFO: Pod pvc-snapshottable-data-tester-xbkgf has the following logs: 
Sep  5 06:39:37.266: INFO: Deleting pod "pvc-snapshottable-data-tester-xbkgf" in namespace "snapshotting-6495"
Sep  5 06:39:37.280: INFO: Wait up to 5m0s for pod "pvc-snapshottable-data-tester-xbkgf" to be fully deleted
STEP: creating a pvc from the snapshot
STEP: starting a pod to use the snapshot
Sep  5 06:39:51.312: INFO: Running '/usr/local/bin/kubectl --server=https://172.24.5.176:6443 --kubeconfig=/root/.kube/config --namespace=snapshotting-6495 exec restored-pvc-tester-nwmgv --namespace=snapshotting-6495 -- 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":3,"skipped":100,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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  5 06:40:30.598: 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  5 06:40:30.626: INFO: Creating resource for dynamic PV
Sep  5 06:40:30.626: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(cinder.csi.openstack.org) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-6259-e2e-sch5lcz
STEP: creating a claim
Sep  5 06:40:30.635: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  5 06:40:30.650: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgklp4l] to have phase Bound
Sep  5 06:40:30.654: INFO: PersistentVolumeClaim cinder.csi.openstack.orgklp4l found but phase is Pending instead of Bound.
Sep  5 06:40:32.659: INFO: PersistentVolumeClaim cinder.csi.openstack.orgklp4l found and phase=Bound (2.009009271s)
STEP: Creating pod pod-subpath-test-dynamicpv-fdxn
STEP: Checking for subpath error in container status
Sep  5 06:40:48.678: INFO: Deleting pod "pod-subpath-test-dynamicpv-fdxn" in namespace "provisioning-6259"
Sep  5 06:40:48.684: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-fdxn" to be fully deleted
STEP: Deleting pod
Sep  5 06:40:50.706: INFO: Deleting pod "pod-subpath-test-dynamicpv-fdxn" in namespace "provisioning-6259"
STEP: Deleting pvc
Sep  5 06:40:50.709: INFO: Deleting PersistentVolumeClaim "cinder.csi.openstack.orgklp4l"
... skipping 9 lines ...

• [SLOW TEST:30.149 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":4,"skipped":195,"failed":0}
SSSSSSSSSSS
------------------------------
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 110 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":5,"skipped":213,"failed":0}
SSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (delayed binding)] topology 
  should provision a volume and schedule a pod with AllowedTopologies
  test/e2e/storage/testsuites/topology.go:166
[BeforeEach] [Testpattern: Dynamic PV (delayed binding)] topology
... skipping 35 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":6,"skipped":227,"failed":0}
SSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] provisioning 
  should provision storage with pvc data source in parallel [Slow]
  test/e2e/storage/testsuites/provisioning.go:459
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] provisioning
... skipping 123 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":7,"skipped":357,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ext4)] volumes 
  should allow exec of files on the volume
  test/e2e/storage/testsuites/volumes.go:198
[BeforeEach] [Testpattern: Dynamic PV (ext4)] volumes
... skipping 14 lines ...
Sep  5 06:42:56.384: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  5 06:42:56.394: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgpcdct] to have phase Bound
Sep  5 06:42:56.400: INFO: PersistentVolumeClaim cinder.csi.openstack.orgpcdct found but phase is Pending instead of Bound.
Sep  5 06:42:58.404: INFO: PersistentVolumeClaim cinder.csi.openstack.orgpcdct found and phase=Bound (2.010303982s)
STEP: Creating pod exec-volume-test-dynamicpv-xqkr
STEP: Creating a pod to test exec-volume-test
Sep  5 06:42:58.421: INFO: Waiting up to 5m0s for pod "exec-volume-test-dynamicpv-xqkr" in namespace "volume-6628" to be "Succeeded or Failed"
Sep  5 06:42:58.425: INFO: Pod "exec-volume-test-dynamicpv-xqkr": Phase="Pending", Reason="", readiness=false. Elapsed: 4.265053ms
Sep  5 06:43:00.430: INFO: Pod "exec-volume-test-dynamicpv-xqkr": Phase="Pending", Reason="", readiness=false. Elapsed: 2.009236805s
Sep  5 06:43:02.436: INFO: Pod "exec-volume-test-dynamicpv-xqkr": Phase="Pending", Reason="", readiness=false. Elapsed: 4.014864695s
Sep  5 06:43:04.442: INFO: Pod "exec-volume-test-dynamicpv-xqkr": Phase="Pending", Reason="", readiness=false. Elapsed: 6.021407444s
Sep  5 06:43:06.449: INFO: Pod "exec-volume-test-dynamicpv-xqkr": Phase="Pending", Reason="", readiness=false. Elapsed: 8.028221241s
Sep  5 06:43:08.455: INFO: Pod "exec-volume-test-dynamicpv-xqkr": Phase="Pending", Reason="", readiness=false. Elapsed: 10.034114569s
Sep  5 06:43:10.459: INFO: Pod "exec-volume-test-dynamicpv-xqkr": Phase="Pending", Reason="", readiness=false. Elapsed: 12.038132271s
Sep  5 06:43:12.464: INFO: Pod "exec-volume-test-dynamicpv-xqkr": Phase="Running", Reason="", readiness=false. Elapsed: 14.043105272s
Sep  5 06:43:14.470: INFO: Pod "exec-volume-test-dynamicpv-xqkr": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.048707403s
STEP: Saw pod success
Sep  5 06:43:14.470: INFO: Pod "exec-volume-test-dynamicpv-xqkr" satisfied condition "Succeeded or Failed"
Sep  5 06:43:14.475: INFO: Trying to get logs from node k3s-master pod exec-volume-test-dynamicpv-xqkr container exec-container-dynamicpv-xqkr: <nil>
STEP: delete the pod
Sep  5 06:43:14.499: INFO: Waiting for pod exec-volume-test-dynamicpv-xqkr to disappear
Sep  5 06:43:14.503: INFO: Pod exec-volume-test-dynamicpv-xqkr no longer exists
STEP: Deleting pod exec-volume-test-dynamicpv-xqkr
Sep  5 06:43:14.503: INFO: Deleting pod "exec-volume-test-dynamicpv-xqkr" in namespace "volume-6628"
... skipping 14 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":8,"skipped":400,"failed":0}
SSSSSSSS
------------------------------
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  5 06:43:24.601: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  5 06:43:24.611: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgdvqln] to have phase Bound
Sep  5 06:43:24.621: INFO: PersistentVolumeClaim cinder.csi.openstack.orgdvqln found but phase is Pending instead of Bound.
Sep  5 06:43:26.630: INFO: PersistentVolumeClaim cinder.csi.openstack.orgdvqln found and phase=Bound (2.018691035s)
STEP: Creating pod exec-volume-test-dynamicpv-fzc5
STEP: Creating a pod to test exec-volume-test
Sep  5 06:43:26.645: INFO: Waiting up to 5m0s for pod "exec-volume-test-dynamicpv-fzc5" in namespace "volume-2694" to be "Succeeded or Failed"
Sep  5 06:43:26.651: INFO: Pod "exec-volume-test-dynamicpv-fzc5": Phase="Pending", Reason="", readiness=false. Elapsed: 6.225827ms
Sep  5 06:43:28.657: INFO: Pod "exec-volume-test-dynamicpv-fzc5": Phase="Pending", Reason="", readiness=false. Elapsed: 2.01201652s
Sep  5 06:43:30.664: INFO: Pod "exec-volume-test-dynamicpv-fzc5": Phase="Pending", Reason="", readiness=false. Elapsed: 4.018935855s
Sep  5 06:43:32.669: INFO: Pod "exec-volume-test-dynamicpv-fzc5": Phase="Pending", Reason="", readiness=false. Elapsed: 6.023494539s
Sep  5 06:43:34.679: INFO: Pod "exec-volume-test-dynamicpv-fzc5": Phase="Pending", Reason="", readiness=false. Elapsed: 8.033785832s
Sep  5 06:43:36.685: INFO: Pod "exec-volume-test-dynamicpv-fzc5": Phase="Running", Reason="", readiness=true. Elapsed: 10.039335416s
Sep  5 06:43:38.689: INFO: Pod "exec-volume-test-dynamicpv-fzc5": Phase="Running", Reason="", readiness=false. Elapsed: 12.043482844s
Sep  5 06:43:40.695: INFO: Pod "exec-volume-test-dynamicpv-fzc5": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.049485632s
STEP: Saw pod success
Sep  5 06:43:40.695: INFO: Pod "exec-volume-test-dynamicpv-fzc5" satisfied condition "Succeeded or Failed"
Sep  5 06:43:40.697: INFO: Trying to get logs from node k3s-master pod exec-volume-test-dynamicpv-fzc5 container exec-container-dynamicpv-fzc5: <nil>
STEP: delete the pod
Sep  5 06:43:40.721: INFO: Waiting for pod exec-volume-test-dynamicpv-fzc5 to disappear
Sep  5 06:43:40.725: INFO: Pod exec-volume-test-dynamicpv-fzc5 no longer exists
STEP: Deleting pod exec-volume-test-dynamicpv-fzc5
Sep  5 06:43:40.725: INFO: Deleting pod "exec-volume-test-dynamicpv-fzc5" in namespace "volume-2694"
... 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":9,"skipped":408,"failed":0}
SSSSSSSSSS
------------------------------
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 147 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":10,"skipped":435,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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 36 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":11,"skipped":472,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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":12,"skipped":505,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath 
  should support creating multiple subpath from same volumes [Slow]
  test/e2e/storage/testsuites/subpath.go:296
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
... skipping 14 lines ...
Sep  5 06:47:52.137: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  5 06:47:52.145: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.org4h87g] to have phase Bound
Sep  5 06:47:52.153: INFO: PersistentVolumeClaim cinder.csi.openstack.org4h87g found but phase is Pending instead of Bound.
Sep  5 06:47:54.158: INFO: PersistentVolumeClaim cinder.csi.openstack.org4h87g found and phase=Bound (2.012372018s)
STEP: Creating pod pod-subpath-test-dynamicpv-x9b9
STEP: Creating a pod to test multi_subpath
Sep  5 06:47:54.172: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-x9b9" in namespace "provisioning-7556" to be "Succeeded or Failed"
Sep  5 06:47:54.178: INFO: Pod "pod-subpath-test-dynamicpv-x9b9": Phase="Pending", Reason="", readiness=false. Elapsed: 5.716533ms
Sep  5 06:47:56.182: INFO: Pod "pod-subpath-test-dynamicpv-x9b9": Phase="Pending", Reason="", readiness=false. Elapsed: 2.009789593s
Sep  5 06:47:58.186: INFO: Pod "pod-subpath-test-dynamicpv-x9b9": Phase="Pending", Reason="", readiness=false. Elapsed: 4.013884131s
Sep  5 06:48:00.191: INFO: Pod "pod-subpath-test-dynamicpv-x9b9": Phase="Pending", Reason="", readiness=false. Elapsed: 6.019592611s
Sep  5 06:48:02.201: INFO: Pod "pod-subpath-test-dynamicpv-x9b9": Phase="Pending", Reason="", readiness=false. Elapsed: 8.029461595s
Sep  5 06:48:04.208: INFO: Pod "pod-subpath-test-dynamicpv-x9b9": Phase="Pending", Reason="", readiness=false. Elapsed: 10.035987334s
Sep  5 06:48:06.214: INFO: Pod "pod-subpath-test-dynamicpv-x9b9": Phase="Pending", Reason="", readiness=false. Elapsed: 12.04182506s
Sep  5 06:48:08.219: INFO: Pod "pod-subpath-test-dynamicpv-x9b9": Phase="Pending", Reason="", readiness=false. Elapsed: 14.047040667s
Sep  5 06:48:10.226: INFO: Pod "pod-subpath-test-dynamicpv-x9b9": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.054076813s
STEP: Saw pod success
Sep  5 06:48:10.226: INFO: Pod "pod-subpath-test-dynamicpv-x9b9" satisfied condition "Succeeded or Failed"
Sep  5 06:48:10.234: INFO: Trying to get logs from node k3s-master pod pod-subpath-test-dynamicpv-x9b9 container test-container-subpath-dynamicpv-x9b9: <nil>
STEP: delete the pod
Sep  5 06:48:10.281: INFO: Waiting for pod pod-subpath-test-dynamicpv-x9b9 to disappear
Sep  5 06:48:10.289: INFO: Pod pod-subpath-test-dynamicpv-x9b9 no longer exists
STEP: Deleting pod
Sep  5 06:48:10.289: INFO: Deleting pod "pod-subpath-test-dynamicpv-x9b9" in namespace "provisioning-7556"
... skipping 14 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":13,"skipped":583,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Inline-volume (default fs)] subPath 
  should support creating multiple subpath from same volumes [Slow]
  test/e2e/storage/testsuites/subpath.go:296
[BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
... skipping 14 lines ...

    test/e2e/storage/external/external.go:262
------------------------------
SSSSSSSSSSSSSSSSSS
------------------------------
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  5 06:48:20.335: 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 114 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":14,"skipped":761,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic 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: Dynamic PV (filesystem volmode)] multiVolume [Slow]
... skipping 106 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":15,"skipped":817,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] multiVolume [Slow] 
  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
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] multiVolume [Slow]
... skipping 14 lines ...

    test/e2e/storage/framework/testsuite.go:121
------------------------------
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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  5 06:50:13.554: 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 66 lines ...
Sep  5 06:50:13.600: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  5 06:50:13.611: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.org7wls9] to have phase Bound
Sep  5 06:50:13.618: INFO: PersistentVolumeClaim cinder.csi.openstack.org7wls9 found but phase is Pending instead of Bound.
Sep  5 06:50:15.624: INFO: PersistentVolumeClaim cinder.csi.openstack.org7wls9 found and phase=Bound (2.012716591s)
STEP: [init] starting a pod to use the claim
STEP: [init] check pod success
Sep  5 06:50:15.651: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-8x9v6" in namespace "snapshotting-6294" to be "Succeeded or Failed"
Sep  5 06:50:15.657: INFO: Pod "pvc-snapshottable-tester-8x9v6": Phase="Pending", Reason="", readiness=false. Elapsed: 6.45256ms
Sep  5 06:50:17.662: INFO: Pod "pvc-snapshottable-tester-8x9v6": Phase="Pending", Reason="", readiness=false. Elapsed: 2.011326057s
Sep  5 06:50:19.667: INFO: Pod "pvc-snapshottable-tester-8x9v6": Phase="Pending", Reason="", readiness=false. Elapsed: 4.016421546s
Sep  5 06:50:21.674: INFO: Pod "pvc-snapshottable-tester-8x9v6": Phase="Pending", Reason="", readiness=false. Elapsed: 6.023718031s
Sep  5 06:50:23.679: INFO: Pod "pvc-snapshottable-tester-8x9v6": Phase="Pending", Reason="", readiness=false. Elapsed: 8.028311738s
Sep  5 06:50:25.685: INFO: Pod "pvc-snapshottable-tester-8x9v6": Phase="Pending", Reason="", readiness=false. Elapsed: 10.034644672s
Sep  5 06:50:27.690: INFO: Pod "pvc-snapshottable-tester-8x9v6": Phase="Pending", Reason="", readiness=false. Elapsed: 12.039144143s
Sep  5 06:50:29.695: INFO: Pod "pvc-snapshottable-tester-8x9v6": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.044205676s
STEP: Saw pod success
Sep  5 06:50:29.695: INFO: Pod "pvc-snapshottable-tester-8x9v6" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
Sep  5 06:50:29.701: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.org7wls9] to have phase Bound
Sep  5 06:50:29.706: INFO: PersistentVolumeClaim cinder.csi.openstack.org7wls9 found and phase=Bound (4.045604ms)
STEP: [init] checking the PV
STEP: [init] deleting the pod
Sep  5 06:50:29.729: INFO: Pod pvc-snapshottable-tester-8x9v6 has the following logs: 
... skipping 38 lines ...
Sep  5 06:50:45.920: INFO: WaitUntil finished successfully after 2.012860925s
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  5 06:50:45.959: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-data-tester-jblxg" in namespace "snapshotting-6294" to be "Succeeded or Failed"
Sep  5 06:50:45.964: INFO: Pod "pvc-snapshottable-data-tester-jblxg": Phase="Pending", Reason="", readiness=false. Elapsed: 4.387782ms
Sep  5 06:50:47.973: INFO: Pod "pvc-snapshottable-data-tester-jblxg": Phase="Pending", Reason="", readiness=false. Elapsed: 2.013970659s
Sep  5 06:50:49.981: INFO: Pod "pvc-snapshottable-data-tester-jblxg": Phase="Pending", Reason="", readiness=false. Elapsed: 4.02169618s
Sep  5 06:50:51.986: INFO: Pod "pvc-snapshottable-data-tester-jblxg": Phase="Pending", Reason="", readiness=false. Elapsed: 6.026922567s
Sep  5 06:50:53.991: INFO: Pod "pvc-snapshottable-data-tester-jblxg": Phase="Pending", Reason="", readiness=false. Elapsed: 8.032054578s
Sep  5 06:50:55.995: INFO: Pod "pvc-snapshottable-data-tester-jblxg": Phase="Running", Reason="", readiness=false. Elapsed: 10.036179667s
Sep  5 06:50:58.000: INFO: Pod "pvc-snapshottable-data-tester-jblxg": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.040471931s
STEP: Saw pod success
Sep  5 06:50:58.000: INFO: Pod "pvc-snapshottable-data-tester-jblxg" satisfied condition "Succeeded or Failed"
Sep  5 06:50:58.012: INFO: Pod pvc-snapshottable-data-tester-jblxg has the following logs: 
Sep  5 06:50:58.012: INFO: Deleting pod "pvc-snapshottable-data-tester-jblxg" in namespace "snapshotting-6294"
Sep  5 06:50:58.022: INFO: Wait up to 5m0s for pod "pvc-snapshottable-data-tester-jblxg" to be fully deleted
STEP: creating a pvc from the snapshot
STEP: starting a pod to use the snapshot
Sep  5 06:51:08.066: INFO: Running '/usr/local/bin/kubectl --server=https://172.24.5.176:6443 --kubeconfig=/root/.kube/config --namespace=snapshotting-6294 exec restored-pvc-tester-x4cft --namespace=snapshotting-6294 -- cat /mnt/test/data'
... skipping 35 lines ...
Sep  5 06:51:32.413: INFO: volumesnapshotcontents pre-provisioned-snapcontent-031a997f-31d9-4dac-8a5a-c073ba423516 has been found and is not deleted
Sep  5 06:51:33.422: INFO: volumesnapshotcontents pre-provisioned-snapcontent-031a997f-31d9-4dac-8a5a-c073ba423516 has been found and is not deleted
Sep  5 06:51:34.429: INFO: volumesnapshotcontents pre-provisioned-snapcontent-031a997f-31d9-4dac-8a5a-c073ba423516 has been found and is not deleted
Sep  5 06:51:35.437: INFO: volumesnapshotcontents pre-provisioned-snapcontent-031a997f-31d9-4dac-8a5a-c073ba423516 has been found and is not deleted
Sep  5 06:51:36.442: INFO: volumesnapshotcontents pre-provisioned-snapcontent-031a997f-31d9-4dac-8a5a-c073ba423516 has been found and is not deleted
Sep  5 06:51:37.446: INFO: volumesnapshotcontents pre-provisioned-snapcontent-031a997f-31d9-4dac-8a5a-c073ba423516 has been found and is not deleted
Sep  5 06:51:38.447: INFO: WaitUntil failed after reaching the timeout 30s
[AfterEach] volume snapshot controller
  test/e2e/storage/testsuites/snapshottable.go:172
Sep  5 06:51:38.457: INFO: Pod restored-pvc-tester-x4cft has the following logs: 
Sep  5 06:51:38.457: INFO: Deleting pod "restored-pvc-tester-x4cft" in namespace "snapshotting-6294"
Sep  5 06:51:38.462: INFO: Wait up to 5m0s for pod "restored-pvc-tester-x4cft" to be fully deleted
Sep  5 06:51:42.470: INFO: deleting claim "snapshotting-6294"/"pvc-8jzbf"
... 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":16,"skipped":988,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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 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":17,"skipped":1074,"failed":0}
SSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Inline-volume (ext3)] volumes 
  should store data
  test/e2e/storage/testsuites/volumes.go:161
[BeforeEach] [Testpattern: Inline-volume (ext3)] volumes
... skipping 143 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  5 06:52:30.707: INFO: volume type "DynamicPV" is not ephemeral
[AfterEach] volume snapshot controller
  test/e2e/storage/testsuites/snapshottable.go:172
Sep  5 06:52:30.712: INFO: Error getting logs for pod restored-pvc-tester-nwmgv: the server could not find the requested resource (get pods restored-pvc-tester-nwmgv)
Sep  5 06:52:30.712: INFO: Deleting pod "restored-pvc-tester-nwmgv" in namespace "snapshotting-6495"
Sep  5 06:52:30.715: INFO: deleting claim "snapshotting-6495"/"pvc-ljf4c"
Sep  5 06:52:30.725: INFO: deleting snapshot class "snapshotting-649599dkt"
Sep  5 06:52:30.728: INFO: Waiting up to 5m0s for volumesnapshotclasses snapshotting-649599dkt to be deleted
Sep  5 06:52:30.731: INFO: volumesnapshotclasses snapshotting-649599dkt is not found and has been deleted
Sep  5 06:52:30.731: INFO: WaitUntil finished successfully after 2.365388ms
... skipping 195 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":18,"skipped":1357,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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, check deletion (ephemeral)
  test/e2e/storage/testsuites/snapshottable.go:177
[BeforeEach] [Testpattern: Dynamic Snapshot (retain policy)] snapshottable[Feature:VolumeSnapshotDataSource]
... skipping 31 lines ...

        test/e2e/storage/testsuites/snapshottable.go:179
------------------------------
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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  5 06:53:14.922: 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  5 06:53:14.977: INFO: Creating resource for dynamic PV
Sep  5 06:53:14.977: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(cinder.csi.openstack.org) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-9964-e2e-scf7r2r
STEP: creating a claim
Sep  5 06:53:14.984: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  5 06:53:14.997: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.org5rd2n] to have phase Bound
Sep  5 06:53:15.027: INFO: PersistentVolumeClaim cinder.csi.openstack.org5rd2n found but phase is Pending instead of Bound.
Sep  5 06:53:17.032: INFO: PersistentVolumeClaim cinder.csi.openstack.org5rd2n found and phase=Bound (2.035079397s)
STEP: Creating pod pod-subpath-test-dynamicpv-vksk
STEP: Checking for subpath error in container status
Sep  5 06:53:29.070: INFO: Deleting pod "pod-subpath-test-dynamicpv-vksk" in namespace "provisioning-9964"
Sep  5 06:53:29.085: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-vksk" to be fully deleted
STEP: Deleting pod
Sep  5 06:53:31.105: INFO: Deleting pod "pod-subpath-test-dynamicpv-vksk" in namespace "provisioning-9964"
STEP: Deleting pvc
Sep  5 06:53:31.110: INFO: Deleting PersistentVolumeClaim "cinder.csi.openstack.org5rd2n"
... skipping 11 lines ...

• [SLOW TEST:36.249 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":19,"skipped":1432,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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 37 lines ...
Sep  5 06:53:51.224: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  5 06:53:51.232: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.org7r44q] to have phase Bound
Sep  5 06:53:51.238: INFO: PersistentVolumeClaim cinder.csi.openstack.org7r44q found but phase is Pending instead of Bound.
Sep  5 06:53:53.242: INFO: PersistentVolumeClaim cinder.csi.openstack.org7r44q found and phase=Bound (2.010133694s)
STEP: [init] starting a pod to use the claim
STEP: [init] check pod success
Sep  5 06:53:53.256: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-qt7pn" in namespace "snapshotting-986" to be "Succeeded or Failed"
Sep  5 06:53:53.260: INFO: Pod "pvc-snapshottable-tester-qt7pn": Phase="Pending", Reason="", readiness=false. Elapsed: 3.51294ms
Sep  5 06:53:55.265: INFO: Pod "pvc-snapshottable-tester-qt7pn": Phase="Pending", Reason="", readiness=false. Elapsed: 2.008298199s
Sep  5 06:53:57.269: INFO: Pod "pvc-snapshottable-tester-qt7pn": Phase="Pending", Reason="", readiness=false. Elapsed: 4.012833326s
Sep  5 06:53:59.279: INFO: Pod "pvc-snapshottable-tester-qt7pn": Phase="Pending", Reason="", readiness=false. Elapsed: 6.022617287s
Sep  5 06:54:01.284: INFO: Pod "pvc-snapshottable-tester-qt7pn": Phase="Pending", Reason="", readiness=false. Elapsed: 8.02757153s
Sep  5 06:54:03.289: INFO: Pod "pvc-snapshottable-tester-qt7pn": Phase="Pending", Reason="", readiness=false. Elapsed: 10.032760541s
Sep  5 06:54:05.294: INFO: Pod "pvc-snapshottable-tester-qt7pn": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.037626866s
STEP: Saw pod success
Sep  5 06:54:05.294: INFO: Pod "pvc-snapshottable-tester-qt7pn" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
Sep  5 06:54:05.296: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.org7r44q] to have phase Bound
Sep  5 06:54:05.299: INFO: PersistentVolumeClaim cinder.csi.openstack.org7r44q found and phase=Bound (2.377616ms)
STEP: [init] checking the PV
STEP: [init] deleting the pod
Sep  5 06:54:05.312: INFO: Pod pvc-snapshottable-tester-qt7pn has the following logs: 
... skipping 15 lines ...
Sep  5 06:54:15.423: INFO: received snapshotStatus map[boundVolumeSnapshotContentName:snapcontent-c48d8f0f-1f45-48d2-a83a-baf60005f37b creationTime:2022-09-05T06:54:13Z readyToUse:true restoreSize:1Gi]
Sep  5 06:54:15.423: INFO: snapshotContentName snapcontent-c48d8f0f-1f45-48d2-a83a-baf60005f37b
STEP: checking the snapshot
STEP: checking the SnapshotContent
STEP: Modifying source data test
STEP: modifying the data in the source PVC
Sep  5 06:54:15.438: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-data-tester-d7wd8" in namespace "snapshotting-986" to be "Succeeded or Failed"
Sep  5 06:54:15.450: INFO: Pod "pvc-snapshottable-data-tester-d7wd8": Phase="Pending", Reason="", readiness=false. Elapsed: 11.533658ms
Sep  5 06:54:17.457: INFO: Pod "pvc-snapshottable-data-tester-d7wd8": Phase="Pending", Reason="", readiness=false. Elapsed: 2.01856425s
Sep  5 06:54:19.461: INFO: Pod "pvc-snapshottable-data-tester-d7wd8": Phase="Pending", Reason="", readiness=false. Elapsed: 4.023372578s
Sep  5 06:54:21.466: INFO: Pod "pvc-snapshottable-data-tester-d7wd8": Phase="Pending", Reason="", readiness=false. Elapsed: 6.028063516s
Sep  5 06:54:23.470: INFO: Pod "pvc-snapshottable-data-tester-d7wd8": Phase="Pending", Reason="", readiness=false. Elapsed: 8.032137429s
Sep  5 06:54:25.474: INFO: Pod "pvc-snapshottable-data-tester-d7wd8": Phase="Pending", Reason="", readiness=false. Elapsed: 10.035757158s
Sep  5 06:54:27.479: INFO: Pod "pvc-snapshottable-data-tester-d7wd8": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.04121007s
STEP: Saw pod success
Sep  5 06:54:27.479: INFO: Pod "pvc-snapshottable-data-tester-d7wd8" satisfied condition "Succeeded or Failed"
Sep  5 06:54:27.489: INFO: Pod pvc-snapshottable-data-tester-d7wd8 has the following logs: 
Sep  5 06:54:27.489: INFO: Deleting pod "pvc-snapshottable-data-tester-d7wd8" in namespace "snapshotting-986"
Sep  5 06:54:27.499: INFO: Wait up to 5m0s for pod "pvc-snapshottable-data-tester-d7wd8" to be fully deleted
STEP: creating a pvc from the snapshot
STEP: starting a pod to use the snapshot
Sep  5 06:54:37.562: INFO: Running '/usr/local/bin/kubectl --server=https://172.24.5.176:6443 --kubeconfig=/root/.kube/config --namespace=snapshotting-986 exec restored-pvc-tester-qg699 --namespace=snapshotting-986 -- cat /mnt/test/data'
... skipping 35 lines ...
Sep  5 06:55:01.902: INFO: volumesnapshotcontents snapcontent-c48d8f0f-1f45-48d2-a83a-baf60005f37b has been found and is not deleted
Sep  5 06:55:02.906: INFO: volumesnapshotcontents snapcontent-c48d8f0f-1f45-48d2-a83a-baf60005f37b has been found and is not deleted
Sep  5 06:55:03.910: INFO: volumesnapshotcontents snapcontent-c48d8f0f-1f45-48d2-a83a-baf60005f37b has been found and is not deleted
Sep  5 06:55:04.917: INFO: volumesnapshotcontents snapcontent-c48d8f0f-1f45-48d2-a83a-baf60005f37b has been found and is not deleted
Sep  5 06:55:05.921: INFO: volumesnapshotcontents snapcontent-c48d8f0f-1f45-48d2-a83a-baf60005f37b has been found and is not deleted
Sep  5 06:55:06.928: INFO: volumesnapshotcontents snapcontent-c48d8f0f-1f45-48d2-a83a-baf60005f37b has been found and is not deleted
Sep  5 06:55:07.928: INFO: WaitUntil failed after reaching the timeout 30s
[AfterEach] volume snapshot controller
  test/e2e/storage/testsuites/snapshottable.go:172
Sep  5 06:55:07.941: INFO: Pod restored-pvc-tester-qg699 has the following logs: 
Sep  5 06:55:07.941: INFO: Deleting pod "restored-pvc-tester-qg699" in namespace "snapshotting-986"
Sep  5 06:55:07.949: INFO: Wait up to 5m0s for pod "restored-pvc-tester-qg699" to be fully deleted
Sep  5 06:55:09.964: INFO: deleting claim "snapshotting-986"/"pvc-5x7xn"
... 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":20,"skipped":1460,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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 37 lines ...
Sep  5 06:55:17.147: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  5 06:55:17.162: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgl7g5z] to have phase Bound
Sep  5 06:55:17.178: INFO: PersistentVolumeClaim cinder.csi.openstack.orgl7g5z found but phase is Pending instead of Bound.
Sep  5 06:55:19.183: INFO: PersistentVolumeClaim cinder.csi.openstack.orgl7g5z found and phase=Bound (2.021588173s)
STEP: [init] starting a pod to use the claim
STEP: [init] check pod success
Sep  5 06:55:19.202: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-t9pzh" in namespace "snapshotting-4813" to be "Succeeded or Failed"
Sep  5 06:55:19.205: INFO: Pod "pvc-snapshottable-tester-t9pzh": Phase="Pending", Reason="", readiness=false. Elapsed: 3.549974ms
Sep  5 06:55:21.211: INFO: Pod "pvc-snapshottable-tester-t9pzh": Phase="Pending", Reason="", readiness=false. Elapsed: 2.009073383s
Sep  5 06:55:23.216: INFO: Pod "pvc-snapshottable-tester-t9pzh": Phase="Pending", Reason="", readiness=false. Elapsed: 4.013717447s
Sep  5 06:55:25.221: INFO: Pod "pvc-snapshottable-tester-t9pzh": Phase="Pending", Reason="", readiness=false. Elapsed: 6.019469905s
Sep  5 06:55:27.232: INFO: Pod "pvc-snapshottable-tester-t9pzh": Phase="Pending", Reason="", readiness=false. Elapsed: 8.030144224s
Sep  5 06:55:29.238: INFO: Pod "pvc-snapshottable-tester-t9pzh": Phase="Pending", Reason="", readiness=false. Elapsed: 10.035772314s
Sep  5 06:55:31.242: INFO: Pod "pvc-snapshottable-tester-t9pzh": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.039795655s
STEP: Saw pod success
Sep  5 06:55:31.242: INFO: Pod "pvc-snapshottable-tester-t9pzh" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
Sep  5 06:55:31.244: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgl7g5z] to have phase Bound
Sep  5 06:55:31.247: INFO: PersistentVolumeClaim cinder.csi.openstack.orgl7g5z found and phase=Bound (3.024671ms)
STEP: [init] checking the PV
STEP: [init] deleting the pod
Sep  5 06:55:31.265: INFO: Pod pvc-snapshottable-tester-t9pzh has the following logs: 
... skipping 35 lines ...
Sep  5 06:55:41.401: INFO: WaitUntil finished successfully after 2.012958136s
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  5 06:55:41.423: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-data-tester-pdppl" in namespace "snapshotting-4813" to be "Succeeded or Failed"
Sep  5 06:55:41.428: INFO: Pod "pvc-snapshottable-data-tester-pdppl": Phase="Pending", Reason="", readiness=false. Elapsed: 4.806526ms
Sep  5 06:55:43.432: INFO: Pod "pvc-snapshottable-data-tester-pdppl": Phase="Pending", Reason="", readiness=false. Elapsed: 2.008983041s
Sep  5 06:55:45.437: INFO: Pod "pvc-snapshottable-data-tester-pdppl": Phase="Pending", Reason="", readiness=false. Elapsed: 4.013864447s
Sep  5 06:55:47.441: INFO: Pod "pvc-snapshottable-data-tester-pdppl": Phase="Pending", Reason="", readiness=false. Elapsed: 6.018167924s
Sep  5 06:55:49.450: INFO: Pod "pvc-snapshottable-data-tester-pdppl": Phase="Pending", Reason="", readiness=false. Elapsed: 8.026814983s
Sep  5 06:55:51.455: INFO: Pod "pvc-snapshottable-data-tester-pdppl": Phase="Running", Reason="", readiness=false. Elapsed: 10.03221838s
Sep  5 06:55:53.464: INFO: Pod "pvc-snapshottable-data-tester-pdppl": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.041269266s
STEP: Saw pod success
Sep  5 06:55:53.464: INFO: Pod "pvc-snapshottable-data-tester-pdppl" satisfied condition "Succeeded or Failed"
Sep  5 06:55:53.483: INFO: Pod pvc-snapshottable-data-tester-pdppl has the following logs: 
Sep  5 06:55:53.483: INFO: Deleting pod "pvc-snapshottable-data-tester-pdppl" in namespace "snapshotting-4813"
Sep  5 06:55:53.501: INFO: Wait up to 5m0s for pod "pvc-snapshottable-data-tester-pdppl" to be fully deleted
STEP: creating a pvc from the snapshot
STEP: starting a pod to use the snapshot
Sep  5 06:56:05.576: INFO: Running '/usr/local/bin/kubectl --server=https://172.24.5.176:6443 --kubeconfig=/root/.kube/config --namespace=snapshotting-4813 exec restored-pvc-tester-rfvxw --namespace=snapshotting-4813 -- 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":21,"skipped":1530,"failed":0}
SSSSSSSSSSSSSSSS
------------------------------
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 138 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":22,"skipped":1638,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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  5 06:57:20.778: 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 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 230 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":23,"skipped":1799,"failed":0}
SSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ext3)] volumes 
  should store data
  test/e2e/storage/testsuites/volumes.go:161
[BeforeEach] [Testpattern: Dynamic PV (ext3)] volumes
... skipping 100 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":24,"skipped":1813,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath 
  should support file as subpath [LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:232
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
... skipping 164 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":25,"skipped":1864,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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
  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
    (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":26,"skipped":1892,"failed":0}
SSSSSS
------------------------------
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
... skipping 162 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":27,"skipped":1960,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow] 
  should concurrently access the single volume from pods on different node
  test/e2e/storage/testsuites/multivolume.go:451
[BeforeEach] [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow]
... skipping 137 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":28,"skipped":2016,"failed":0}
SSSSSSSS
------------------------------
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  5 07:01:16.552: 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  5 07:01:16.607: INFO: Creating resource for dynamic PV
Sep  5 07:01:16.607: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(cinder.csi.openstack.org) supported size:{ 1Mi} 
STEP: creating a StorageClass volumemode-4399-e2e-scjws68
STEP: creating a claim
Sep  5 07:01:16.636: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgplkf7] to have phase Bound
Sep  5 07:01:16.640: INFO: PersistentVolumeClaim cinder.csi.openstack.orgplkf7 found but phase is Pending instead of Bound.
Sep  5 07:01:18.644: INFO: PersistentVolumeClaim cinder.csi.openstack.orgplkf7 found and phase=Bound (2.008440513s)
STEP: Creating pod
STEP: Waiting for the pod to fail
Sep  5 07:01:20.668: INFO: Deleting pod "pod-527c6e18-fea3-461e-a6f2-0d0052e80c1e" in namespace "volumemode-4399"
Sep  5 07:01:20.674: INFO: Wait up to 5m0s for pod "pod-527c6e18-fea3-461e-a6f2-0d0052e80c1e" to be fully deleted
STEP: Deleting pvc
Sep  5 07:01:22.686: INFO: Deleting PersistentVolumeClaim "cinder.csi.openstack.orgplkf7"
Sep  5 07:01:22.693: INFO: Waiting up to 5m0s for PersistentVolume pvc-92bb1319-a5ac-4ace-9490-5036e09d51a1 to get deleted
Sep  5 07:01:22.696: INFO: PersistentVolume pvc-92bb1319-a5ac-4ace-9490-5036e09d51a1 found and phase=Bound (2.89322ms)
... skipping 7 lines ...

• [SLOW TEST:16.176 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":29,"skipped":2024,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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 119 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":30,"skipped":2097,"failed":0}
SSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath 
  should support existing single file [LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:221
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
... skipping 14 lines ...
Sep  5 07:01:46.312: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  5 07:01:46.329: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgcfw9q] to have phase Bound
Sep  5 07:01:46.345: INFO: PersistentVolumeClaim cinder.csi.openstack.orgcfw9q found but phase is Pending instead of Bound.
Sep  5 07:01:48.351: INFO: PersistentVolumeClaim cinder.csi.openstack.orgcfw9q found and phase=Bound (2.02167539s)
STEP: Creating pod pod-subpath-test-dynamicpv-94t2
STEP: Creating a pod to test subpath
Sep  5 07:01:48.363: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-94t2" in namespace "provisioning-6228" to be "Succeeded or Failed"
Sep  5 07:01:48.365: INFO: Pod "pod-subpath-test-dynamicpv-94t2": Phase="Pending", Reason="", readiness=false. Elapsed: 2.559572ms
Sep  5 07:01:50.374: INFO: Pod "pod-subpath-test-dynamicpv-94t2": Phase="Pending", Reason="", readiness=false. Elapsed: 2.011663856s
Sep  5 07:01:52.379: INFO: Pod "pod-subpath-test-dynamicpv-94t2": Phase="Pending", Reason="", readiness=false. Elapsed: 4.016094504s
Sep  5 07:01:54.387: INFO: Pod "pod-subpath-test-dynamicpv-94t2": Phase="Pending", Reason="", readiness=false. Elapsed: 6.024676646s
Sep  5 07:01:56.391: INFO: Pod "pod-subpath-test-dynamicpv-94t2": Phase="Pending", Reason="", readiness=false. Elapsed: 8.028786964s
Sep  5 07:01:58.397: INFO: Pod "pod-subpath-test-dynamicpv-94t2": Phase="Pending", Reason="", readiness=false. Elapsed: 10.034129492s
Sep  5 07:02:00.403: INFO: Pod "pod-subpath-test-dynamicpv-94t2": Phase="Pending", Reason="", readiness=false. Elapsed: 12.040087086s
Sep  5 07:02:02.411: INFO: Pod "pod-subpath-test-dynamicpv-94t2": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.04870314s
STEP: Saw pod success
Sep  5 07:02:02.411: INFO: Pod "pod-subpath-test-dynamicpv-94t2" satisfied condition "Succeeded or Failed"
Sep  5 07:02:02.414: INFO: Trying to get logs from node k3s-master pod pod-subpath-test-dynamicpv-94t2 container test-container-subpath-dynamicpv-94t2: <nil>
STEP: delete the pod
Sep  5 07:02:02.441: INFO: Waiting for pod pod-subpath-test-dynamicpv-94t2 to disappear
Sep  5 07:02:02.448: INFO: Pod pod-subpath-test-dynamicpv-94t2 no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-94t2
Sep  5 07:02:02.448: INFO: Deleting pod "pod-subpath-test-dynamicpv-94t2" in namespace "provisioning-6228"
... 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":31,"skipped":2112,"failed":0}
SSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (block volmode)] multiVolume [Slow] 
  should concurrently access the single volume from pods on the same node
  test/e2e/storage/testsuites/multivolume.go:298
[BeforeEach] [Testpattern: Pre-provisioned PV (block volmode)] multiVolume [Slow]
... 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 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":32,"skipped":2180,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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)
  test/e2e/storage/testsuites/snapshottable.go:177
[BeforeEach] [Testpattern: Ephemeral Snapshot (delete 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  5 07:02:48.940: INFO: Creating resource for dynamic PV
Sep  5 07:02:48.940: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(cinder.csi.openstack.org) supported size:{ 1Mi} 
STEP: creating a StorageClass snapshotting-6688-e2e-sc55tfq
STEP: [init] starting a pod to use the claim
Sep  5 07:02:48.971: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-gljmh" in namespace "snapshotting-6688" to be "Succeeded or Failed"
Sep  5 07:02:48.979: INFO: Pod "pvc-snapshottable-tester-gljmh": Phase="Pending", Reason="", readiness=false. Elapsed: 7.858388ms
Sep  5 07:02:50.984: INFO: Pod "pvc-snapshottable-tester-gljmh": Phase="Pending", Reason="", readiness=false. Elapsed: 2.013049845s
Sep  5 07:02:52.989: INFO: Pod "pvc-snapshottable-tester-gljmh": Phase="Pending", Reason="", readiness=false. Elapsed: 4.017889017s
Sep  5 07:02:55.000: INFO: Pod "pvc-snapshottable-tester-gljmh": Phase="Pending", Reason="", readiness=false. Elapsed: 6.02888493s
Sep  5 07:02:57.008: INFO: Pod "pvc-snapshottable-tester-gljmh": Phase="Pending", Reason="", readiness=false. Elapsed: 8.037223435s
Sep  5 07:02:59.014: INFO: Pod "pvc-snapshottable-tester-gljmh": Phase="Pending", Reason="", readiness=false. Elapsed: 10.042457246s
Sep  5 07:03:01.019: INFO: Pod "pvc-snapshottable-tester-gljmh": Phase="Pending", Reason="", readiness=false. Elapsed: 12.047355785s
Sep  5 07:03:03.026: INFO: Pod "pvc-snapshottable-tester-gljmh": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.054543042s
STEP: Saw pod success
Sep  5 07:03:03.026: INFO: Pod "pvc-snapshottable-tester-gljmh" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
STEP: creating a SnapshotClass
STEP: creating a dynamic VolumeSnapshot
Sep  5 07:03:03.051: INFO: Waiting up to 5m0s for VolumeSnapshot snapshot-cg5zh to become ready
Sep  5 07:03:03.055: INFO: VolumeSnapshot snapshot-cg5zh found but is not ready.
Sep  5 07:03:05.062: INFO: VolumeSnapshot snapshot-cg5zh found but is not ready.
... skipping 47 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":33,"skipped":2206,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] 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 (ntfs)][Feature:Windows] multiVolume [Slow]
... skipping 82 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":34,"skipped":2272,"failed":0}
SSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Inline-volume (xfs)][Slow] volumes 
  should allow exec of files on the volume
  test/e2e/storage/testsuites/volumes.go:198
[BeforeEach] [Testpattern: Inline-volume (xfs)][Slow] volumes
... skipping 164 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":35,"skipped":2465,"failed":0}
SSS
------------------------------
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":36,"skipped":2468,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (ntfs)][Feature:Windows] volumes 
  should allow exec of files on the volume
  test/e2e/storage/testsuites/volumes.go:198
[BeforeEach] [Testpattern: Pre-provisioned PV (ntfs)][Feature:Windows] volumes
... skipping 71 lines ...
Sep  5 07:06:40.374: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  5 07:06:40.385: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.org9fwxb] to have phase Bound
Sep  5 07:06:40.397: INFO: PersistentVolumeClaim cinder.csi.openstack.org9fwxb found but phase is Pending instead of Bound.
Sep  5 07:06:42.402: INFO: PersistentVolumeClaim cinder.csi.openstack.org9fwxb found and phase=Bound (2.017377218s)
STEP: Creating pod pod-subpath-test-dynamicpv-5txn
STEP: Creating a pod to test atomic-volume-subpath
Sep  5 07:06:42.414: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-5txn" in namespace "provisioning-6510" to be "Succeeded or Failed"
Sep  5 07:06:42.418: INFO: Pod "pod-subpath-test-dynamicpv-5txn": Phase="Pending", Reason="", readiness=false. Elapsed: 3.658994ms
Sep  5 07:06:44.422: INFO: Pod "pod-subpath-test-dynamicpv-5txn": Phase="Pending", Reason="", readiness=false. Elapsed: 2.007539262s
Sep  5 07:06:46.427: INFO: Pod "pod-subpath-test-dynamicpv-5txn": Phase="Pending", Reason="", readiness=false. Elapsed: 4.012555131s
Sep  5 07:06:48.433: INFO: Pod "pod-subpath-test-dynamicpv-5txn": Phase="Pending", Reason="", readiness=false. Elapsed: 6.019270782s
Sep  5 07:06:50.437: INFO: Pod "pod-subpath-test-dynamicpv-5txn": Phase="Pending", Reason="", readiness=false. Elapsed: 8.023485637s
Sep  5 07:06:52.441: INFO: Pod "pod-subpath-test-dynamicpv-5txn": Phase="Running", Reason="", readiness=true. Elapsed: 10.026702994s
... skipping 7 lines ...
Sep  5 07:07:08.490: INFO: Pod "pod-subpath-test-dynamicpv-5txn": Phase="Running", Reason="", readiness=true. Elapsed: 26.07638805s
Sep  5 07:07:10.496: INFO: Pod "pod-subpath-test-dynamicpv-5txn": Phase="Running", Reason="", readiness=true. Elapsed: 28.082306334s
Sep  5 07:07:12.502: INFO: Pod "pod-subpath-test-dynamicpv-5txn": Phase="Running", Reason="", readiness=true. Elapsed: 30.087979546s
Sep  5 07:07:14.509: INFO: Pod "pod-subpath-test-dynamicpv-5txn": Phase="Running", Reason="", readiness=false. Elapsed: 32.095173139s
Sep  5 07:07:16.518: INFO: Pod "pod-subpath-test-dynamicpv-5txn": Phase="Succeeded", Reason="", readiness=false. Elapsed: 34.103550977s
STEP: Saw pod success
Sep  5 07:07:16.518: INFO: Pod "pod-subpath-test-dynamicpv-5txn" satisfied condition "Succeeded or Failed"
Sep  5 07:07:16.524: INFO: Trying to get logs from node k3s-master pod pod-subpath-test-dynamicpv-5txn container test-container-subpath-dynamicpv-5txn: <nil>
STEP: delete the pod
Sep  5 07:07:16.558: INFO: Waiting for pod pod-subpath-test-dynamicpv-5txn to disappear
Sep  5 07:07:16.561: INFO: Pod pod-subpath-test-dynamicpv-5txn no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-5txn
Sep  5 07:07:16.561: INFO: Deleting pod "pod-subpath-test-dynamicpv-5txn" in namespace "provisioning-6510"
... 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 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":37,"skipped":2645,"failed":0}
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned 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: Pre-provisioned PV (block volmode)] multiVolume [Slow]
  test/e2e/storage/framework/testsuite.go:51
Sep  5 07:07:26.619: INFO: Driver "cinder.csi.openstack.org" does not support volume type "PreprovisionedPV" - skipping
... skipping 76 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":38,"skipped":2687,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (block volmode)] provisioning 
  should provision storage with pvc data source in parallel [Slow]
  test/e2e/storage/testsuites/provisioning.go:459
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] provisioning
... skipping 280 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":39,"skipped":2730,"failed":0}
SSSSS
------------------------------
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 14 lines ...

    test/e2e/storage/external/external.go:262
------------------------------
SSS
------------------------------
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  5 07:11:09.074: 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 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 13 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  5 07:11:09.127: INFO: volume type "GenericEphemeralVolume" is ephemeral
[AfterEach] volume snapshot controller
  test/e2e/storage/testsuites/snapshottable.go:172
Sep  5 07:11:09.153: INFO: Error getting logs for pod restored-pvc-tester-q2bpt: the server could not find the requested resource (get pods restored-pvc-tester-q2bpt)
Sep  5 07:11:09.153: INFO: Deleting pod "restored-pvc-tester-q2bpt" in namespace "snapshotting-6688"
Sep  5 07:11:09.160: INFO: deleting snapshot class "snapshotting-66882mvqr"
Sep  5 07:11:09.172: INFO: Waiting up to 5m0s for volumesnapshotclasses snapshotting-66882mvqr to be deleted
Sep  5 07:11:09.189: INFO: volumesnapshotclasses snapshotting-66882mvqr is not found and has been deleted
Sep  5 07:11:09.189: INFO: WaitUntil finished successfully after 17.129274ms
Sep  5 07:11:09.189: INFO: Deleting pod "pvc-snapshottable-tester-gljmh" in namespace "snapshotting-6688"
... skipping 250 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":40,"skipped":2944,"failed":0}
SSSSSSSSSSS
------------------------------
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 ...

    test/e2e/storage/external/external.go:262
------------------------------
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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  5 07:11:57.534: 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 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":41,"skipped":3091,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (xfs)][Slow] volumes 
  should allow exec of files on the volume
  test/e2e/storage/testsuites/volumes.go:198
[BeforeEach] [Testpattern: Dynamic PV (xfs)][Slow] volumes
... skipping 14 lines ...
Sep  5 07:12:53.985: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  5 07:12:53.993: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgltth2] to have phase Bound
Sep  5 07:12:53.998: INFO: PersistentVolumeClaim cinder.csi.openstack.orgltth2 found but phase is Pending instead of Bound.
Sep  5 07:12:56.001: INFO: PersistentVolumeClaim cinder.csi.openstack.orgltth2 found and phase=Bound (2.00776574s)
STEP: Creating pod exec-volume-test-dynamicpv-qb75
STEP: Creating a pod to test exec-volume-test
Sep  5 07:12:56.013: INFO: Waiting up to 5m0s for pod "exec-volume-test-dynamicpv-qb75" in namespace "volume-3634" to be "Succeeded or Failed"
Sep  5 07:12:56.019: INFO: Pod "exec-volume-test-dynamicpv-qb75": Phase="Pending", Reason="", readiness=false. Elapsed: 5.866636ms
Sep  5 07:12:58.024: INFO: Pod "exec-volume-test-dynamicpv-qb75": Phase="Pending", Reason="", readiness=false. Elapsed: 2.010849717s
Sep  5 07:13:00.028: INFO: Pod "exec-volume-test-dynamicpv-qb75": Phase="Pending", Reason="", readiness=false. Elapsed: 4.015572023s
Sep  5 07:13:02.034: INFO: Pod "exec-volume-test-dynamicpv-qb75": Phase="Pending", Reason="", readiness=false. Elapsed: 6.021175126s
Sep  5 07:13:04.038: INFO: Pod "exec-volume-test-dynamicpv-qb75": Phase="Pending", Reason="", readiness=false. Elapsed: 8.025684249s
Sep  5 07:13:06.044: INFO: Pod "exec-volume-test-dynamicpv-qb75": Phase="Pending", Reason="", readiness=false. Elapsed: 10.030970942s
Sep  5 07:13:08.049: INFO: Pod "exec-volume-test-dynamicpv-qb75": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.0364452s
STEP: Saw pod success
Sep  5 07:13:08.049: INFO: Pod "exec-volume-test-dynamicpv-qb75" satisfied condition "Succeeded or Failed"
Sep  5 07:13:08.053: INFO: Trying to get logs from node k3s-master pod exec-volume-test-dynamicpv-qb75 container exec-container-dynamicpv-qb75: <nil>
STEP: delete the pod
Sep  5 07:13:08.082: INFO: Waiting for pod exec-volume-test-dynamicpv-qb75 to disappear
Sep  5 07:13:08.090: INFO: Pod exec-volume-test-dynamicpv-qb75 no longer exists
STEP: Deleting pod exec-volume-test-dynamicpv-qb75
Sep  5 07:13:08.090: INFO: Deleting pod "exec-volume-test-dynamicpv-qb75" in namespace "volume-3634"
... skipping 13 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":42,"skipped":3145,"failed":0}
SSS
------------------------------
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  5 07:13:13.175: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  5 07:13:13.183: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.org7sgqp] to have phase Bound
Sep  5 07:13:13.199: INFO: PersistentVolumeClaim cinder.csi.openstack.org7sgqp found but phase is Pending instead of Bound.
Sep  5 07:13:15.211: INFO: PersistentVolumeClaim cinder.csi.openstack.org7sgqp found and phase=Bound (2.027484009s)
STEP: Expanding non-expandable pvc
Sep  5 07:13:15.218: INFO: currentPvcSize {{1073741824 0} {<nil>} 1Gi BinarySI}, newSize {{2147483648 0} {<nil>}  BinarySI}
Sep  5 07:13:15.231: INFO: Error updating pvc cinder.csi.openstack.org7sgqp: persistentvolumeclaims "cinder.csi.openstack.org7sgqp" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:13:17.241: INFO: Error updating pvc cinder.csi.openstack.org7sgqp: persistentvolumeclaims "cinder.csi.openstack.org7sgqp" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:13:19.240: INFO: Error updating pvc cinder.csi.openstack.org7sgqp: persistentvolumeclaims "cinder.csi.openstack.org7sgqp" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:13:21.240: INFO: Error updating pvc cinder.csi.openstack.org7sgqp: persistentvolumeclaims "cinder.csi.openstack.org7sgqp" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:13:23.240: INFO: Error updating pvc cinder.csi.openstack.org7sgqp: persistentvolumeclaims "cinder.csi.openstack.org7sgqp" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:13:25.250: INFO: Error updating pvc cinder.csi.openstack.org7sgqp: persistentvolumeclaims "cinder.csi.openstack.org7sgqp" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:13:27.240: INFO: Error updating pvc cinder.csi.openstack.org7sgqp: persistentvolumeclaims "cinder.csi.openstack.org7sgqp" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:13:29.240: INFO: Error updating pvc cinder.csi.openstack.org7sgqp: persistentvolumeclaims "cinder.csi.openstack.org7sgqp" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:13:31.244: INFO: Error updating pvc cinder.csi.openstack.org7sgqp: persistentvolumeclaims "cinder.csi.openstack.org7sgqp" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:13:33.242: INFO: Error updating pvc cinder.csi.openstack.org7sgqp: persistentvolumeclaims "cinder.csi.openstack.org7sgqp" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:13:35.254: INFO: Error updating pvc cinder.csi.openstack.org7sgqp: persistentvolumeclaims "cinder.csi.openstack.org7sgqp" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:13:37.241: INFO: Error updating pvc cinder.csi.openstack.org7sgqp: persistentvolumeclaims "cinder.csi.openstack.org7sgqp" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:13:39.243: INFO: Error updating pvc cinder.csi.openstack.org7sgqp: persistentvolumeclaims "cinder.csi.openstack.org7sgqp" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:13:41.241: INFO: Error updating pvc cinder.csi.openstack.org7sgqp: persistentvolumeclaims "cinder.csi.openstack.org7sgqp" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:13:43.248: INFO: Error updating pvc cinder.csi.openstack.org7sgqp: persistentvolumeclaims "cinder.csi.openstack.org7sgqp" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:13:45.238: INFO: Error updating pvc cinder.csi.openstack.org7sgqp: persistentvolumeclaims "cinder.csi.openstack.org7sgqp" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:13:45.244: INFO: Error updating pvc cinder.csi.openstack.org7sgqp: persistentvolumeclaims "cinder.csi.openstack.org7sgqp" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
STEP: Deleting pvc
Sep  5 07:13:45.244: INFO: Deleting PersistentVolumeClaim "cinder.csi.openstack.org7sgqp"
Sep  5 07:13:45.258: INFO: Waiting up to 5m0s for PersistentVolume pvc-5857140d-172c-404b-9368-5509dbb5b660 to get deleted
Sep  5 07:13:45.262: INFO: PersistentVolume pvc-5857140d-172c-404b-9368-5509dbb5b660 found and phase=Bound (3.972485ms)
Sep  5 07:13:50.267: INFO: PersistentVolume pvc-5857140d-172c-404b-9368-5509dbb5b660 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":43,"skipped":3148,"failed":0}
S
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] provisioning 
  should provision storage with mount options
  test/e2e/storage/testsuites/provisioning.go:187
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] provisioning
... skipping 77 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":44,"skipped":3186,"failed":0}
SSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] 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: Dynamic PV (ntfs)][Feature:Windows] multiVolume [Slow]
... skipping 100 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":45,"skipped":3232,"failed":0}
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  5 07:17:34.133: 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 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 76 lines ...
Sep  5 07:17:34.222: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  5 07:17:34.238: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgdmpg7] to have phase Bound
Sep  5 07:17:34.255: INFO: PersistentVolumeClaim cinder.csi.openstack.orgdmpg7 found but phase is Pending instead of Bound.
Sep  5 07:17:36.261: INFO: PersistentVolumeClaim cinder.csi.openstack.orgdmpg7 found and phase=Bound (2.023739092s)
STEP: Creating pod pod-subpath-test-dynamicpv-v69m
STEP: Creating a pod to test subpath
Sep  5 07:17:36.277: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-v69m" in namespace "provisioning-2052" to be "Succeeded or Failed"
Sep  5 07:17:36.283: INFO: Pod "pod-subpath-test-dynamicpv-v69m": Phase="Pending", Reason="", readiness=false. Elapsed: 5.679078ms
Sep  5 07:17:38.288: INFO: Pod "pod-subpath-test-dynamicpv-v69m": Phase="Pending", Reason="", readiness=false. Elapsed: 2.011131418s
Sep  5 07:17:40.296: INFO: Pod "pod-subpath-test-dynamicpv-v69m": Phase="Pending", Reason="", readiness=false. Elapsed: 4.019023046s
Sep  5 07:17:42.303: INFO: Pod "pod-subpath-test-dynamicpv-v69m": Phase="Pending", Reason="", readiness=false. Elapsed: 6.025512344s
Sep  5 07:17:44.308: INFO: Pod "pod-subpath-test-dynamicpv-v69m": Phase="Pending", Reason="", readiness=false. Elapsed: 8.030516391s
Sep  5 07:17:46.319: INFO: Pod "pod-subpath-test-dynamicpv-v69m": Phase="Pending", Reason="", readiness=false. Elapsed: 10.041580539s
Sep  5 07:17:48.327: INFO: Pod "pod-subpath-test-dynamicpv-v69m": Phase="Pending", Reason="", readiness=false. Elapsed: 12.049497194s
Sep  5 07:17:50.333: INFO: Pod "pod-subpath-test-dynamicpv-v69m": Phase="Pending", Reason="", readiness=false. Elapsed: 14.055622172s
Sep  5 07:17:52.338: INFO: Pod "pod-subpath-test-dynamicpv-v69m": Phase="Succeeded", Reason="", readiness=false. Elapsed: 16.061335947s
STEP: Saw pod success
Sep  5 07:17:52.339: INFO: Pod "pod-subpath-test-dynamicpv-v69m" satisfied condition "Succeeded or Failed"
Sep  5 07:17:52.342: INFO: Trying to get logs from node k3s-master pod pod-subpath-test-dynamicpv-v69m container test-container-subpath-dynamicpv-v69m: <nil>
STEP: delete the pod
Sep  5 07:17:52.370: INFO: Waiting for pod pod-subpath-test-dynamicpv-v69m to disappear
Sep  5 07:17:52.379: INFO: Pod pod-subpath-test-dynamicpv-v69m no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-v69m
Sep  5 07:17:52.379: INFO: Deleting pod "pod-subpath-test-dynamicpv-v69m" in namespace "provisioning-2052"
... 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":46,"skipped":3362,"failed":0}
SSSSSSSSSSSSSS
------------------------------
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 different node
  test/e2e/storage/testsuites/multivolume.go:248
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow]
... skipping 88 lines ...
[It] should check snapshot fields, check restore correctly works, check deletion (ephemeral)
  test/e2e/storage/testsuites/snapshottable.go:177
Sep  5 07:18:02.590: INFO: Creating resource for dynamic PV
Sep  5 07:18:02.590: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(cinder.csi.openstack.org) supported size:{ 1Mi} 
STEP: creating a StorageClass snapshotting-5156-e2e-scl5m82
STEP: [init] starting a pod to use the claim
Sep  5 07:18:02.625: INFO: Waiting up to 15m0s for pod "pvc-snapshottable-tester-xs5xv" in namespace "snapshotting-5156" to be "Succeeded or Failed"
Sep  5 07:18:02.676: INFO: Pod "pvc-snapshottable-tester-xs5xv": Phase="Pending", Reason="", readiness=false. Elapsed: 51.682808ms
Sep  5 07:18:04.683: INFO: Pod "pvc-snapshottable-tester-xs5xv": Phase="Pending", Reason="", readiness=false. Elapsed: 2.058005676s
Sep  5 07:18:06.687: INFO: Pod "pvc-snapshottable-tester-xs5xv": Phase="Pending", Reason="", readiness=false. Elapsed: 4.062331474s
Sep  5 07:18:08.692: INFO: Pod "pvc-snapshottable-tester-xs5xv": Phase="Pending", Reason="", readiness=false. Elapsed: 6.066954605s
Sep  5 07:18:10.699: INFO: Pod "pvc-snapshottable-tester-xs5xv": Phase="Pending", Reason="", readiness=false. Elapsed: 8.074200648s
Sep  5 07:18:12.703: INFO: Pod "pvc-snapshottable-tester-xs5xv": Phase="Pending", Reason="", readiness=false. Elapsed: 10.078459882s
Sep  5 07:18:14.708: INFO: Pod "pvc-snapshottable-tester-xs5xv": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.083661697s
STEP: Saw pod success
Sep  5 07:18:14.708: INFO: Pod "pvc-snapshottable-tester-xs5xv" satisfied condition "Succeeded or Failed"
STEP: [init] checking the claim
STEP: creating a SnapshotClass
STEP: creating a dynamic VolumeSnapshot
Sep  5 07:18:14.732: INFO: Waiting up to 5m0s for VolumeSnapshot snapshot-t8dbt to become ready
Sep  5 07:18:14.741: INFO: VolumeSnapshot snapshot-t8dbt found but is not ready.
Sep  5 07:18:16.746: INFO: VolumeSnapshot snapshot-t8dbt found but is not ready.
... skipping 43 lines ...
Sep  5 07:18:56.942: INFO: volumesnapshotcontents snapcontent-103c1534-1e3b-452c-a69c-f30570f70688 has been found and is not deleted
Sep  5 07:18:57.948: INFO: volumesnapshotcontents snapcontent-103c1534-1e3b-452c-a69c-f30570f70688 has been found and is not deleted
Sep  5 07:18:58.954: INFO: volumesnapshotcontents snapcontent-103c1534-1e3b-452c-a69c-f30570f70688 has been found and is not deleted
Sep  5 07:18:59.960: INFO: volumesnapshotcontents snapcontent-103c1534-1e3b-452c-a69c-f30570f70688 has been found and is not deleted
Sep  5 07:19:00.966: INFO: volumesnapshotcontents snapcontent-103c1534-1e3b-452c-a69c-f30570f70688 has been found and is not deleted
Sep  5 07:19:01.973: INFO: volumesnapshotcontents snapcontent-103c1534-1e3b-452c-a69c-f30570f70688 has been found and is not deleted
Sep  5 07:19:02.973: INFO: WaitUntil failed after reaching the timeout 30s
[AfterEach] volume snapshot controller
  test/e2e/storage/testsuites/snapshottable.go:172
Sep  5 07:19:02.993: INFO: Pod restored-pvc-tester-z7rwb has the following logs: 
Sep  5 07:19:02.993: INFO: Deleting pod "restored-pvc-tester-z7rwb" in namespace "snapshotting-5156"
Sep  5 07:19:02.999: INFO: Wait up to 5m0s for pod "restored-pvc-tester-z7rwb" to be fully deleted
Sep  5 07:19:35.016: INFO: deleting snapshot "snapshotting-5156"/"snapshot-t8dbt"
... 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":47,"skipped":3406,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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 104 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":48,"skipped":3546,"failed":0}
SSSSSSSSSSSSSSSSSS
------------------------------
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 138 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":49,"skipped":3564,"failed":0}
SSSS
------------------------------
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 37 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":50,"skipped":3568,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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  5 07:21:44.840: INFO: volume type "GenericEphemeralVolume" is ephemeral
[AfterEach] volume snapshot controller
  test/e2e/storage/testsuites/snapshottable.go:172
Sep  5 07:21:44.845: INFO: Error getting logs for pod restored-pvc-tester-z7rwb: the server could not find the requested resource (get pods restored-pvc-tester-z7rwb)
Sep  5 07:21:44.845: INFO: Deleting pod "restored-pvc-tester-z7rwb" in namespace "snapshotting-5156"
Sep  5 07:21:44.873: INFO: deleting snapshot content "snapcontent-103c1534-1e3b-452c-a69c-f30570f70688"
Sep  5 07:21:44.893: INFO: deleting snapshot class "snapshotting-5156z99jx"
Sep  5 07:21:44.899: INFO: Waiting up to 5m0s for volumesnapshotclasses snapshotting-5156z99jx to be deleted
Sep  5 07:21:44.904: INFO: volumesnapshotclasses snapshotting-5156z99jx is not found and has been deleted
Sep  5 07:21:44.904: INFO: WaitUntil finished successfully after 5.247222ms
... skipping 104 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":51,"skipped":3696,"failed":0}
SSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Inline-volume (default fs)] subPath 
  should support existing directories when readOnly specified in the volumeSource
  test/e2e/storage/testsuites/subpath.go:397
[BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
... skipping 72 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":52,"skipped":3706,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (ext4)] volumes 
  should allow exec of files on the volume
  test/e2e/storage/testsuites/volumes.go:198
[BeforeEach] [Testpattern: Pre-provisioned PV (ext4)] volumes
... skipping 14 lines ...

    test/e2e/storage/external/external.go:262
------------------------------
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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  5 07:22:36.797: 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 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 42 lines ...
STEP: creating a claim
Sep  5 07:22:36.873: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  5 07:22:36.891: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.org9pmfn] to have phase Bound
Sep  5 07:22:36.905: INFO: PersistentVolumeClaim cinder.csi.openstack.org9pmfn found but phase is Pending instead of Bound.
Sep  5 07:22:38.910: INFO: PersistentVolumeClaim cinder.csi.openstack.org9pmfn found and phase=Bound (2.019726939s)
STEP: Creating pod to format volume volume-prep-provisioning-631
Sep  5 07:22:38.921: INFO: Waiting up to 5m0s for pod "volume-prep-provisioning-631" in namespace "provisioning-631" to be "Succeeded or Failed"
Sep  5 07:22:38.926: INFO: Pod "volume-prep-provisioning-631": Phase="Pending", Reason="", readiness=false. Elapsed: 5.100782ms
Sep  5 07:22:40.933: INFO: Pod "volume-prep-provisioning-631": Phase="Pending", Reason="", readiness=false. Elapsed: 2.01195507s
Sep  5 07:22:42.938: INFO: Pod "volume-prep-provisioning-631": Phase="Pending", Reason="", readiness=false. Elapsed: 4.01628314s
Sep  5 07:22:44.943: INFO: Pod "volume-prep-provisioning-631": Phase="Pending", Reason="", readiness=false. Elapsed: 6.02121166s
Sep  5 07:22:46.949: INFO: Pod "volume-prep-provisioning-631": Phase="Pending", Reason="", readiness=false. Elapsed: 8.027825669s
Sep  5 07:22:48.954: INFO: Pod "volume-prep-provisioning-631": Phase="Pending", Reason="", readiness=false. Elapsed: 10.032322049s
Sep  5 07:22:50.958: INFO: Pod "volume-prep-provisioning-631": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.036758021s
STEP: Saw pod success
Sep  5 07:22:50.958: INFO: Pod "volume-prep-provisioning-631" satisfied condition "Succeeded or Failed"
Sep  5 07:22:50.958: INFO: Deleting pod "volume-prep-provisioning-631" in namespace "provisioning-631"
Sep  5 07:22:50.966: INFO: Wait up to 5m0s for pod "volume-prep-provisioning-631" to be fully deleted
STEP: Creating pod pod-subpath-test-dynamicpv-p9sr
STEP: Checking for subpath error in container status
Sep  5 07:23:05.005: INFO: Deleting pod "pod-subpath-test-dynamicpv-p9sr" in namespace "provisioning-631"
Sep  5 07:23:05.012: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-p9sr" to be fully deleted
STEP: Deleting pod
Sep  5 07:23:07.020: INFO: Deleting pod "pod-subpath-test-dynamicpv-p9sr" in namespace "provisioning-631"
STEP: Deleting pvc
Sep  5 07:23:07.023: INFO: Deleting PersistentVolumeClaim "cinder.csi.openstack.org9pmfn"
... 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":53,"skipped":3913,"failed":0}
SSSSSSSSSSSSSSSSSSSS
------------------------------
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 the same node
  test/e2e/storage/testsuites/multivolume.go:209
[BeforeEach] [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow]
... skipping 48 lines ...
Sep  5 07:23:17.217: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  5 07:23:17.234: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.org8k9qm] to have phase Bound
Sep  5 07:23:17.241: INFO: PersistentVolumeClaim cinder.csi.openstack.org8k9qm found but phase is Pending instead of Bound.
Sep  5 07:23:19.244: INFO: PersistentVolumeClaim cinder.csi.openstack.org8k9qm found and phase=Bound (2.010424625s)
STEP: Creating pod pod-subpath-test-dynamicpv-vh2p
STEP: Creating a pod to test subpath
Sep  5 07:23:19.256: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-vh2p" in namespace "provisioning-8330" to be "Succeeded or Failed"
Sep  5 07:23:19.262: INFO: Pod "pod-subpath-test-dynamicpv-vh2p": Phase="Pending", Reason="", readiness=false. Elapsed: 5.818442ms
Sep  5 07:23:21.267: INFO: Pod "pod-subpath-test-dynamicpv-vh2p": Phase="Pending", Reason="", readiness=false. Elapsed: 2.011197142s
Sep  5 07:23:23.272: INFO: Pod "pod-subpath-test-dynamicpv-vh2p": Phase="Pending", Reason="", readiness=false. Elapsed: 4.015702106s
Sep  5 07:23:25.277: INFO: Pod "pod-subpath-test-dynamicpv-vh2p": Phase="Pending", Reason="", readiness=false. Elapsed: 6.021399216s
Sep  5 07:23:27.282: INFO: Pod "pod-subpath-test-dynamicpv-vh2p": Phase="Pending", Reason="", readiness=false. Elapsed: 8.026337494s
Sep  5 07:23:29.292: INFO: Pod "pod-subpath-test-dynamicpv-vh2p": Phase="Pending", Reason="", readiness=false. Elapsed: 10.036401002s
Sep  5 07:23:31.298: INFO: Pod "pod-subpath-test-dynamicpv-vh2p": Phase="Pending", Reason="", readiness=false. Elapsed: 12.04233576s
Sep  5 07:23:33.307: INFO: Pod "pod-subpath-test-dynamicpv-vh2p": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.051377741s
STEP: Saw pod success
Sep  5 07:23:33.307: INFO: Pod "pod-subpath-test-dynamicpv-vh2p" satisfied condition "Succeeded or Failed"
Sep  5 07:23:33.311: INFO: Trying to get logs from node k3s-master pod pod-subpath-test-dynamicpv-vh2p container test-container-volume-dynamicpv-vh2p: <nil>
STEP: delete the pod
Sep  5 07:23:33.343: INFO: Waiting for pod pod-subpath-test-dynamicpv-vh2p to disappear
Sep  5 07:23:33.352: INFO: Pod pod-subpath-test-dynamicpv-vh2p no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-vh2p
Sep  5 07:23:33.352: INFO: Deleting pod "pod-subpath-test-dynamicpv-vh2p" in namespace "provisioning-8330"
... 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":54,"skipped":3995,"failed":0}
SSSSSSSSSSSSSSSSSSSS
------------------------------
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
  test/e2e/storage/testsuites/multivolume.go:138
[BeforeEach] [Testpattern: Dynamic PV (filesystem volmode)] multiVolume [Slow]
... skipping 178 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":55,"skipped":4015,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath 
  should support readOnly file specified in the volumeMount [LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:382
[BeforeEach] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] subPath
... skipping 102 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":56,"skipped":4158,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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  5 07:25:21.236: 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 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 93 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  5 07:25:21.318: INFO: volume type "DynamicPV" is not ephemeral
[AfterEach] volume snapshot controller
  test/e2e/storage/testsuites/snapshottable.go:172
Sep  5 07:25:21.327: INFO: Error getting logs for pod restored-pvc-tester-rfvxw: the server could not find the requested resource (get pods restored-pvc-tester-rfvxw)
Sep  5 07:25:21.327: INFO: Deleting pod "restored-pvc-tester-rfvxw" in namespace "snapshotting-4813"
Sep  5 07:25:21.331: INFO: deleting claim "snapshotting-4813"/"pvc-9v2jh"
Sep  5 07:25:21.340: INFO: deleting snapshot class "snapshotting-481345kdq"
Sep  5 07:25:21.344: INFO: Waiting up to 5m0s for volumesnapshotclasses snapshotting-481345kdq to be deleted
Sep  5 07:25:21.348: INFO: volumesnapshotclasses snapshotting-481345kdq is not found and has been deleted
Sep  5 07:25:21.348: INFO: WaitUntil finished successfully after 4.445892ms
... skipping 130 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":57,"skipped":4243,"failed":0}
SSSSSSS
------------------------------
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 98 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":58,"skipped":4324,"failed":0}
SSSSSSSSSS
------------------------------
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 177 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":59,"skipped":4334,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] subPath 
  should support non-existent path
  test/e2e/storage/testsuites/subpath.go:196
[BeforeEach] [Testpattern: Dynamic PV (default fs)] subPath
... skipping 14 lines ...
Sep  5 07:27:58.459: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  5 07:27:58.479: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgq6fjn] to have phase Bound
Sep  5 07:27:58.483: INFO: PersistentVolumeClaim cinder.csi.openstack.orgq6fjn found but phase is Pending instead of Bound.
Sep  5 07:28:00.488: INFO: PersistentVolumeClaim cinder.csi.openstack.orgq6fjn found and phase=Bound (2.008475656s)
STEP: Creating pod pod-subpath-test-dynamicpv-t4jx
STEP: Creating a pod to test subpath
Sep  5 07:28:00.505: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-t4jx" in namespace "provisioning-3554" to be "Succeeded or Failed"
Sep  5 07:28:00.511: INFO: Pod "pod-subpath-test-dynamicpv-t4jx": Phase="Pending", Reason="", readiness=false. Elapsed: 5.735121ms
Sep  5 07:28:02.515: INFO: Pod "pod-subpath-test-dynamicpv-t4jx": Phase="Pending", Reason="", readiness=false. Elapsed: 2.010050526s
Sep  5 07:28:04.520: INFO: Pod "pod-subpath-test-dynamicpv-t4jx": Phase="Pending", Reason="", readiness=false. Elapsed: 4.015025235s
Sep  5 07:28:06.524: INFO: Pod "pod-subpath-test-dynamicpv-t4jx": Phase="Pending", Reason="", readiness=false. Elapsed: 6.019100757s
Sep  5 07:28:08.529: INFO: Pod "pod-subpath-test-dynamicpv-t4jx": Phase="Pending", Reason="", readiness=false. Elapsed: 8.02398996s
Sep  5 07:28:10.536: INFO: Pod "pod-subpath-test-dynamicpv-t4jx": Phase="Pending", Reason="", readiness=false. Elapsed: 10.030782046s
Sep  5 07:28:12.543: INFO: Pod "pod-subpath-test-dynamicpv-t4jx": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.038240793s
STEP: Saw pod success
Sep  5 07:28:12.543: INFO: Pod "pod-subpath-test-dynamicpv-t4jx" satisfied condition "Succeeded or Failed"
Sep  5 07:28:12.547: INFO: Trying to get logs from node k3s-master pod pod-subpath-test-dynamicpv-t4jx container test-container-volume-dynamicpv-t4jx: <nil>
STEP: delete the pod
Sep  5 07:28:12.582: INFO: Waiting for pod pod-subpath-test-dynamicpv-t4jx to disappear
Sep  5 07:28:12.588: INFO: Pod pod-subpath-test-dynamicpv-t4jx no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-t4jx
Sep  5 07:28:12.588: INFO: Deleting pod "pod-subpath-test-dynamicpv-t4jx" in namespace "provisioning-3554"
... 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 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":60,"skipped":4378,"failed":0}
SSSSSS
------------------------------
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
  test/e2e/storage/testsuites/volume_expand.go:248
[BeforeEach] [Testpattern: Dynamic PV (block volmode)(allowExpansion)] volume-expand
... skipping 40 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":61,"skipped":4384,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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 50 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":62,"skipped":4443,"failed":0}
SSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (filesystem volmode)] volumeLimits 
  should verify that all csinodes have volume limits
  test/e2e/storage/testsuites/volumelimits.go:249
[BeforeEach] [Testpattern: Dynamic PV (filesystem volmode)] volumeLimits
... skipping 47 lines ...

    test/e2e/storage/framework/testsuite.go:121
------------------------------
SSSSSSSSSS
------------------------------
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  5 07:31:51.470: 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  5 07:31:51.521: INFO: found topology map[topology.cinder.csi.openstack.org/zone:nova]
Sep  5 07:31:51.521: 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.066 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
------------------------------
SSSSSSSSSSSSSSS
------------------------------
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  5 07:31:51.537: 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  5 07:31:51.571: INFO: Creating resource for dynamic PV
Sep  5 07:31:51.571: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(cinder.csi.openstack.org) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-3084-e2e-scp89jk
STEP: creating a claim
Sep  5 07:31:51.577: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  5 07:31:51.591: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgdgrqc] to have phase Bound
Sep  5 07:31:51.603: INFO: PersistentVolumeClaim cinder.csi.openstack.orgdgrqc found but phase is Pending instead of Bound.
Sep  5 07:31:53.610: INFO: PersistentVolumeClaim cinder.csi.openstack.orgdgrqc found and phase=Bound (2.018658901s)
STEP: Creating pod pod-subpath-test-dynamicpv-rhmg
STEP: Checking for subpath error in container status
Sep  5 07:32:05.638: INFO: Deleting pod "pod-subpath-test-dynamicpv-rhmg" in namespace "provisioning-3084"
Sep  5 07:32:05.645: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-rhmg" to be fully deleted
STEP: Deleting pod
Sep  5 07:32:07.657: INFO: Deleting pod "pod-subpath-test-dynamicpv-rhmg" in namespace "provisioning-3084"
STEP: Deleting pvc
Sep  5 07:32:07.660: INFO: Deleting PersistentVolumeClaim "cinder.csi.openstack.orgdgrqc"
... skipping 11 lines ...

• [SLOW TEST:36.179 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":63,"skipped":4494,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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 83 lines ...

    test/e2e/storage/framework/testsuite.go:121
------------------------------
SSSSSSSSSSSSSSSSSSSSS
------------------------------
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  5 07:32:27.718: 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  5 07:32:27.803: INFO: found topology map[topology.cinder.csi.openstack.org/zone:nova]
Sep  5 07:32:27.803: 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.102 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 89 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":64,"skipped":4816,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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 313 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":65,"skipped":4885,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (default fs)] subPath 
  should support existing directories when readOnly specified in the volumeSource
  test/e2e/storage/testsuites/subpath.go:397
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
... skipping 105 lines ...
STEP: creating a claim
Sep  5 07:35:02.607: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.org6r8wh] to have phase Bound
Sep  5 07:35:02.622: INFO: PersistentVolumeClaim cinder.csi.openstack.org6r8wh found but phase is Pending instead of Bound.
Sep  5 07:35:04.628: INFO: PersistentVolumeClaim cinder.csi.openstack.org6r8wh found and phase=Bound (2.021418718s)
STEP: Expanding non-expandable pvc
Sep  5 07:35:04.636: INFO: currentPvcSize {{1073741824 0} {<nil>} 1Gi BinarySI}, newSize {{2147483648 0} {<nil>}  BinarySI}
Sep  5 07:35:04.647: INFO: Error updating pvc cinder.csi.openstack.org6r8wh: persistentvolumeclaims "cinder.csi.openstack.org6r8wh" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:35:06.657: INFO: Error updating pvc cinder.csi.openstack.org6r8wh: persistentvolumeclaims "cinder.csi.openstack.org6r8wh" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:35:08.660: INFO: Error updating pvc cinder.csi.openstack.org6r8wh: persistentvolumeclaims "cinder.csi.openstack.org6r8wh" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:35:10.657: INFO: Error updating pvc cinder.csi.openstack.org6r8wh: persistentvolumeclaims "cinder.csi.openstack.org6r8wh" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:35:12.658: INFO: Error updating pvc cinder.csi.openstack.org6r8wh: persistentvolumeclaims "cinder.csi.openstack.org6r8wh" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:35:14.659: INFO: Error updating pvc cinder.csi.openstack.org6r8wh: persistentvolumeclaims "cinder.csi.openstack.org6r8wh" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:35:16.656: INFO: Error updating pvc cinder.csi.openstack.org6r8wh: persistentvolumeclaims "cinder.csi.openstack.org6r8wh" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:35:18.657: INFO: Error updating pvc cinder.csi.openstack.org6r8wh: persistentvolumeclaims "cinder.csi.openstack.org6r8wh" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:35:20.658: INFO: Error updating pvc cinder.csi.openstack.org6r8wh: persistentvolumeclaims "cinder.csi.openstack.org6r8wh" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:35:22.658: INFO: Error updating pvc cinder.csi.openstack.org6r8wh: persistentvolumeclaims "cinder.csi.openstack.org6r8wh" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:35:24.656: INFO: Error updating pvc cinder.csi.openstack.org6r8wh: persistentvolumeclaims "cinder.csi.openstack.org6r8wh" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:35:26.662: INFO: Error updating pvc cinder.csi.openstack.org6r8wh: persistentvolumeclaims "cinder.csi.openstack.org6r8wh" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:35:28.659: INFO: Error updating pvc cinder.csi.openstack.org6r8wh: persistentvolumeclaims "cinder.csi.openstack.org6r8wh" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:35:30.659: INFO: Error updating pvc cinder.csi.openstack.org6r8wh: persistentvolumeclaims "cinder.csi.openstack.org6r8wh" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:35:32.671: INFO: Error updating pvc cinder.csi.openstack.org6r8wh: persistentvolumeclaims "cinder.csi.openstack.org6r8wh" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:35:34.657: INFO: Error updating pvc cinder.csi.openstack.org6r8wh: persistentvolumeclaims "cinder.csi.openstack.org6r8wh" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
Sep  5 07:35:34.664: INFO: Error updating pvc cinder.csi.openstack.org6r8wh: persistentvolumeclaims "cinder.csi.openstack.org6r8wh" is forbidden: only dynamically provisioned pvc can be resized and the storageclass that provisions the pvc must support resize
STEP: Deleting pvc
Sep  5 07:35:34.664: INFO: Deleting PersistentVolumeClaim "cinder.csi.openstack.org6r8wh"
Sep  5 07:35:34.680: INFO: Waiting up to 5m0s for PersistentVolume pvc-8a380fb5-2dda-4fe7-be1b-d2b01f76f719 to get deleted
Sep  5 07:35:34.684: INFO: PersistentVolume pvc-8a380fb5-2dda-4fe7-be1b-d2b01f76f719 found and phase=Bound (3.219372ms)
Sep  5 07:35:39.692: INFO: PersistentVolume pvc-8a380fb5-2dda-4fe7-be1b-d2b01f76f719 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":66,"skipped":5203,"failed":0}
SSSSS
------------------------------
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 174 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":67,"skipped":5262,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] provisioning 
  should provision storage with snapshot data source [Feature:VolumeSnapshotDataSource]
  test/e2e/storage/testsuites/provisioning.go:208
[BeforeEach] [Testpattern: Dynamic PV (default fs)] provisioning
... skipping 113 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":68,"skipped":5292,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (default fs)] volumeIO 
  should write files of various sizes, verify size, validate content [Slow]
  test/e2e/storage/testsuites/volume_io.go:149
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] volumeIO
... skipping 64 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":69,"skipped":5339,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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]
  test/e2e/storage/testsuites/multivolume.go:378
[BeforeEach] [Testpattern: Dynamic PV (xfs)][Slow] multiVolume [Slow]
... skipping 73 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":70,"skipped":5367,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ext4)] multiVolume [Slow] 
  should concurrently access the single volume from pods on different node
  test/e2e/storage/testsuites/multivolume.go:451
[BeforeEach] [Testpattern: Dynamic PV (ext4)] multiVolume [Slow]
... skipping 25 lines ...

    test/e2e/storage/testsuites/multivolume.go:458
------------------------------
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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  5 07:38:30.965: 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  5 07:38:30.991: INFO: Creating resource for dynamic PV
Sep  5 07:38:30.991: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(cinder.csi.openstack.org) supported size:{ 1Mi} 
STEP: creating a StorageClass volumemode-2573-e2e-scxcxgv
STEP: creating a claim
Sep  5 07:38:31.017: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.org46wdk] to have phase Bound
Sep  5 07:38:31.025: INFO: PersistentVolumeClaim cinder.csi.openstack.org46wdk found but phase is Pending instead of Bound.
Sep  5 07:38:33.030: INFO: PersistentVolumeClaim cinder.csi.openstack.org46wdk found and phase=Bound (2.012247495s)
STEP: Creating pod
STEP: Waiting for the pod to fail
Sep  5 07:38:35.053: INFO: Deleting pod "pod-40225469-6ef4-43d9-90cc-f489fdbe4ff7" in namespace "volumemode-2573"
Sep  5 07:38:35.089: INFO: Wait up to 5m0s for pod "pod-40225469-6ef4-43d9-90cc-f489fdbe4ff7" to be fully deleted
STEP: Deleting pvc
Sep  5 07:38:37.112: INFO: Deleting PersistentVolumeClaim "cinder.csi.openstack.org46wdk"
Sep  5 07:38:37.123: INFO: Waiting up to 5m0s for PersistentVolume pvc-4f894f0f-ce2a-4798-960e-400dce9ec955 to get deleted
Sep  5 07:38:37.130: INFO: PersistentVolume pvc-4f894f0f-ce2a-4798-960e-400dce9ec955 found and phase=Bound (6.487815ms)
... skipping 7 lines ...

• [SLOW TEST:16.191 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":71,"skipped":5468,"failed":0}
SSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (ntfs)][Feature:Windows] 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 (ntfs)][Feature:Windows] provisioning
... skipping 311 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":72,"skipped":5639,"failed":0}
SS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Inline-volume (default fs)] subPath 
  should support non-existent path
  test/e2e/storage/testsuites/subpath.go:196
[BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
... skipping 37 lines ...
Sep  5 07:39:27.917: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  5 07:39:27.932: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.org7hb82] to have phase Bound
Sep  5 07:39:27.945: INFO: PersistentVolumeClaim cinder.csi.openstack.org7hb82 found but phase is Pending instead of Bound.
Sep  5 07:39:29.950: INFO: PersistentVolumeClaim cinder.csi.openstack.org7hb82 found and phase=Bound (2.017959016s)
STEP: Creating pod pod-subpath-test-dynamicpv-zf4j
STEP: Creating a pod to test subpath
Sep  5 07:39:29.964: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-zf4j" in namespace "provisioning-8199" to be "Succeeded or Failed"
Sep  5 07:39:29.968: INFO: Pod "pod-subpath-test-dynamicpv-zf4j": Phase="Pending", Reason="", readiness=false. Elapsed: 3.433326ms
Sep  5 07:39:31.973: INFO: Pod "pod-subpath-test-dynamicpv-zf4j": Phase="Pending", Reason="", readiness=false. Elapsed: 2.009230789s
Sep  5 07:39:33.978: INFO: Pod "pod-subpath-test-dynamicpv-zf4j": Phase="Pending", Reason="", readiness=false. Elapsed: 4.013798073s
Sep  5 07:39:35.988: INFO: Pod "pod-subpath-test-dynamicpv-zf4j": Phase="Pending", Reason="", readiness=false. Elapsed: 6.02422139s
Sep  5 07:39:37.994: INFO: Pod "pod-subpath-test-dynamicpv-zf4j": Phase="Pending", Reason="", readiness=false. Elapsed: 8.029947108s
Sep  5 07:39:40.007: INFO: Pod "pod-subpath-test-dynamicpv-zf4j": Phase="Pending", Reason="", readiness=false. Elapsed: 10.042867338s
Sep  5 07:39:42.012: INFO: Pod "pod-subpath-test-dynamicpv-zf4j": Phase="Pending", Reason="", readiness=false. Elapsed: 12.047584398s
Sep  5 07:39:44.016: INFO: Pod "pod-subpath-test-dynamicpv-zf4j": Phase="Succeeded", Reason="", readiness=false. Elapsed: 14.052044264s
STEP: Saw pod success
Sep  5 07:39:44.016: INFO: Pod "pod-subpath-test-dynamicpv-zf4j" satisfied condition "Succeeded or Failed"
Sep  5 07:39:44.019: INFO: Trying to get logs from node k3s-master pod pod-subpath-test-dynamicpv-zf4j container test-container-subpath-dynamicpv-zf4j: <nil>
STEP: delete the pod
Sep  5 07:39:44.054: INFO: Waiting for pod pod-subpath-test-dynamicpv-zf4j to disappear
Sep  5 07:39:44.059: INFO: Pod pod-subpath-test-dynamicpv-zf4j no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-zf4j
Sep  5 07:39:44.059: INFO: Deleting pod "pod-subpath-test-dynamicpv-zf4j" in namespace "provisioning-8199"
STEP: Creating pod pod-subpath-test-dynamicpv-zf4j
STEP: Creating a pod to test subpath
Sep  5 07:39:44.071: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-zf4j" in namespace "provisioning-8199" to be "Succeeded or Failed"
Sep  5 07:39:44.090: INFO: Pod "pod-subpath-test-dynamicpv-zf4j": Phase="Pending", Reason="", readiness=false. Elapsed: 18.914665ms
Sep  5 07:39:46.100: INFO: Pod "pod-subpath-test-dynamicpv-zf4j": Phase="Pending", Reason="", readiness=false. Elapsed: 2.028596559s
Sep  5 07:39:48.105: INFO: Pod "pod-subpath-test-dynamicpv-zf4j": Phase="Pending", Reason="", readiness=false. Elapsed: 4.033651477s
Sep  5 07:39:50.111: INFO: Pod "pod-subpath-test-dynamicpv-zf4j": Phase="Succeeded", Reason="", readiness=false. Elapsed: 6.039602974s
STEP: Saw pod success
Sep  5 07:39:50.111: INFO: Pod "pod-subpath-test-dynamicpv-zf4j" satisfied condition "Succeeded or Failed"
Sep  5 07:39:50.114: INFO: Trying to get logs from node k3s-master pod pod-subpath-test-dynamicpv-zf4j container test-container-subpath-dynamicpv-zf4j: <nil>
STEP: delete the pod
Sep  5 07:39:50.135: INFO: Waiting for pod pod-subpath-test-dynamicpv-zf4j to disappear
Sep  5 07:39:50.138: INFO: Pod pod-subpath-test-dynamicpv-zf4j no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-zf4j
Sep  5 07:39:50.138: INFO: Deleting pod "pod-subpath-test-dynamicpv-zf4j" in namespace "provisioning-8199"
... 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 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":5647,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Generic Ephemeral-volume (default fs)] volumeLimits 
  should verify that all csinodes have volume limits
  test/e2e/storage/testsuites/volumelimits.go:249
[BeforeEach] [Testpattern: Generic Ephemeral-volume (default fs)] volumeLimits
... skipping 162 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":74,"skipped":5763,"failed":0}
SSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Inline-volume (default fs)] subPath 
  should be able to unmount after the subpath directory is deleted [LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:447
[BeforeEach] [Testpattern: Inline-volume (default fs)] subPath
... skipping 48 lines ...

    test/e2e/storage/testsuites/provisioning.go:189
------------------------------
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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  5 07:41:07.722: 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  5 07:41:07.746: INFO: Creating resource for dynamic PV
Sep  5 07:41:07.747: INFO: Using claimSize:1Gi, test suite supported size:{ 1Mi}, driver(cinder.csi.openstack.org) supported size:{ 1Mi} 
STEP: creating a StorageClass provisioning-1458-e2e-sctnfg7
STEP: creating a claim
Sep  5 07:41:07.752: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  5 07:41:07.771: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.org9jgbz] to have phase Bound
Sep  5 07:41:07.778: INFO: PersistentVolumeClaim cinder.csi.openstack.org9jgbz found but phase is Pending instead of Bound.
Sep  5 07:41:09.785: INFO: PersistentVolumeClaim cinder.csi.openstack.org9jgbz found and phase=Bound (2.013656269s)
STEP: Creating pod pod-subpath-test-dynamicpv-sbsq
STEP: Checking for subpath error in container status
Sep  5 07:41:19.807: INFO: Deleting pod "pod-subpath-test-dynamicpv-sbsq" in namespace "provisioning-1458"
Sep  5 07:41:19.813: INFO: Wait up to 5m0s for pod "pod-subpath-test-dynamicpv-sbsq" to be fully deleted
STEP: Deleting pod
Sep  5 07:41:21.821: INFO: Deleting pod "pod-subpath-test-dynamicpv-sbsq" in namespace "provisioning-1458"
STEP: Deleting pvc
Sep  5 07:41:21.825: INFO: Deleting PersistentVolumeClaim "cinder.csi.openstack.org9jgbz"
... skipping 9 lines ...

• [SLOW TEST:24.140 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":75,"skipped":5851,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (filesystem volmode)] multiVolume [Slow] 
  should concurrently access the single volume from pods on the same node
  test/e2e/storage/testsuites/multivolume.go:298
[BeforeEach] [Testpattern: Pre-provisioned PV (filesystem volmode)] multiVolume [Slow]
... skipping 97 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":76,"skipped":5955,"failed":0}
SSSSSSSSSS
------------------------------
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  5 07:43:25.449: 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 54 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":77,"skipped":6027,"failed":0}
SSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Dynamic PV (default fs)] provisioning 
  should provision storage with pvc data source
  test/e2e/storage/testsuites/provisioning.go:421
[BeforeEach] [Testpattern: Dynamic PV (default fs)] provisioning
... skipping 91 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":78,"skipped":6037,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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 102 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":79,"skipped":6083,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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 228 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":80,"skipped":6152,"failed":0}
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]
  test/e2e/storage/framework/testsuite.go:51
[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":81,"skipped":6152,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Generic Ephemeral-volume (block volmode) (late-binding)] ephemeral 
  should support multiple inline ephemeral volumes
  test/e2e/storage/testsuites/ephemeral.go:254
[BeforeEach] [Testpattern: Generic Ephemeral-volume (block volmode) (late-binding)] ephemeral
... skipping 36 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":82,"skipped":6247,"failed":0}
SSSSSSSSSSSSSS
------------------------------
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 96 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":83,"skipped":6261,"failed":0}
SSSSSSSSSSSS
------------------------------
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  5 07:49:28.546: 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.001 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 110 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":84,"skipped":6321,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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, check deletion (ephemeral)
  test/e2e/storage/testsuites/snapshottable.go:177
[BeforeEach] [Testpattern: Pre-provisioned 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, check deletion (ephemeral)
  test/e2e/storage/testsuites/snapshottable.go:177
Sep  5 07:50:13.659: INFO: volume type "DynamicPV" is not ephemeral
[AfterEach] volume snapshot controller
  test/e2e/storage/testsuites/snapshottable.go:172
Sep  5 07:50:13.667: INFO: Error getting logs for pod restored-pvc-tester-x4cft: the server could not find the requested resource (get pods restored-pvc-tester-x4cft)
Sep  5 07:50:13.667: INFO: Deleting pod "restored-pvc-tester-x4cft" in namespace "snapshotting-6294"
Sep  5 07:50:13.670: INFO: deleting claim "snapshotting-6294"/"pvc-8jzbf"
Sep  5 07:50:13.674: INFO: deleting snapshot content "pre-provisioned-snapcontent-031a997f-31d9-4dac-8a5a-c073ba423516"
Sep  5 07:50:13.678: INFO: deleting snapshot class "snapshotting-6294k9rl8"
Sep  5 07:50:13.681: INFO: Waiting up to 5m0s for volumesnapshotclasses snapshotting-6294k9rl8 to be deleted
Sep  5 07:50:13.684: INFO: volumesnapshotclasses snapshotting-6294k9rl8 is not found and has been deleted
... skipping 121 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":85,"skipped":6419,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (default fs)] subPath 
  should support readOnly file specified in the volumeMount [LinuxOnly]
  test/e2e/storage/testsuites/subpath.go:382
[BeforeEach] [Testpattern: Pre-provisioned PV (default fs)] subPath
... skipping 265 lines ...
Sep  5 07:50:58.111: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  5 07:50:58.121: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orggjcmt] to have phase Bound
Sep  5 07:50:58.125: INFO: PersistentVolumeClaim cinder.csi.openstack.orggjcmt found but phase is Pending instead of Bound.
Sep  5 07:51:00.131: INFO: PersistentVolumeClaim cinder.csi.openstack.orggjcmt found and phase=Bound (2.010608252s)
STEP: Creating pod pod-subpath-test-dynamicpv-4252
STEP: Creating a pod to test subpath
Sep  5 07:51:00.144: INFO: Waiting up to 5m0s for pod "pod-subpath-test-dynamicpv-4252" in namespace "provisioning-6026" to be "Succeeded or Failed"
Sep  5 07:51:00.152: INFO: Pod "pod-subpath-test-dynamicpv-4252": Phase="Pending", Reason="", readiness=false. Elapsed: 7.601132ms
Sep  5 07:51:02.157: INFO: Pod "pod-subpath-test-dynamicpv-4252": Phase="Pending", Reason="", readiness=false. Elapsed: 2.012949931s
Sep  5 07:51:04.162: INFO: Pod "pod-subpath-test-dynamicpv-4252": Phase="Pending", Reason="", readiness=false. Elapsed: 4.018087167s
Sep  5 07:51:06.167: INFO: Pod "pod-subpath-test-dynamicpv-4252": Phase="Pending", Reason="", readiness=false. Elapsed: 6.022487809s
Sep  5 07:51:08.176: INFO: Pod "pod-subpath-test-dynamicpv-4252": Phase="Pending", Reason="", readiness=false. Elapsed: 8.031733892s
Sep  5 07:51:10.181: INFO: Pod "pod-subpath-test-dynamicpv-4252": Phase="Pending", Reason="", readiness=false. Elapsed: 10.036507303s
Sep  5 07:51:12.195: INFO: Pod "pod-subpath-test-dynamicpv-4252": Phase="Pending", Reason="", readiness=false. Elapsed: 12.050276258s
Sep  5 07:51:14.205: INFO: Pod "pod-subpath-test-dynamicpv-4252": Phase="Pending", Reason="", readiness=false. Elapsed: 14.060228526s
Sep  5 07:51:16.211: INFO: Pod "pod-subpath-test-dynamicpv-4252": Phase="Pending", Reason="", readiness=false. Elapsed: 16.066965285s
Sep  5 07:51:18.218: INFO: Pod "pod-subpath-test-dynamicpv-4252": Phase="Succeeded", Reason="", readiness=false. Elapsed: 18.074061518s
STEP: Saw pod success
Sep  5 07:51:18.218: INFO: Pod "pod-subpath-test-dynamicpv-4252" satisfied condition "Succeeded or Failed"
Sep  5 07:51:18.225: INFO: Trying to get logs from node k3s-master pod pod-subpath-test-dynamicpv-4252 container test-container-subpath-dynamicpv-4252: <nil>
STEP: delete the pod
Sep  5 07:51:18.272: INFO: Waiting for pod pod-subpath-test-dynamicpv-4252 to disappear
Sep  5 07:51:18.276: INFO: Pod pod-subpath-test-dynamicpv-4252 no longer exists
STEP: Deleting pod pod-subpath-test-dynamicpv-4252
Sep  5 07:51:18.276: INFO: Deleting pod "pod-subpath-test-dynamicpv-4252" in namespace "provisioning-6026"
... 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":86,"skipped":6740,"failed":0}
SSSSSSSS
------------------------------
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
  test/e2e/storage/testsuites/multivolume.go:138
[BeforeEach] [Testpattern: Dynamic PV (block volmode)] multiVolume [Slow]
... skipping 176 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":87,"skipped":6748,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (block 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 (block volmode)] multiVolume [Slow]
... skipping 37 lines ...

    test/e2e/storage/external/external.go:262
------------------------------
SSSSSSSSSSSSSSSSSSS
------------------------------
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  5 07:52:12.803: 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 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
------------------------------
SSSSSSSSSSSS
------------------------------
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  5 07:52:12.804: 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.001 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 20 lines ...
Sep  5 07:52:12.842: INFO: Warning: Making PVC: VolumeMode specified as invalid empty string, treating as nil
Sep  5 07:52:12.859: INFO: Waiting up to timeout=5m0s for PersistentVolumeClaims [cinder.csi.openstack.orgnbnhr] to have phase Bound
Sep  5 07:52:12.879: INFO: PersistentVolumeClaim cinder.csi.openstack.orgnbnhr found but phase is Pending instead of Bound.
Sep  5 07:52:14.883: INFO: PersistentVolumeClaim cinder.csi.openstack.orgnbnhr found and phase=Bound (2.024573024s)
STEP: Creating pod exec-volume-test-dynamicpv-jm62
STEP: Creating a pod to test exec-volume-test
Sep  5 07:52:14.895: INFO: Waiting up to 5m0s for pod "exec-volume-test-dynamicpv-jm62" in namespace "volume-2819" to be "Succeeded or Failed"
Sep  5 07:52:14.898: INFO: Pod "exec-volume-test-dynamicpv-jm62": Phase="Pending", Reason="", readiness=false. Elapsed: 2.707346ms
Sep  5 07:52:16.905: INFO: Pod "exec-volume-test-dynamicpv-jm62": Phase="Pending", Reason="", readiness=false. Elapsed: 2.009612324s
Sep  5 07:52:18.921: INFO: Pod "exec-volume-test-dynamicpv-jm62": Phase="Pending", Reason="", readiness=false. Elapsed: 4.025212074s
Sep  5 07:52:20.930: INFO: Pod "exec-volume-test-dynamicpv-jm62": Phase="Pending", Reason="", readiness=false. Elapsed: 6.034433644s
Sep  5 07:52:22.935: INFO: Pod "exec-volume-test-dynamicpv-jm62": Phase="Pending", Reason="", readiness=false. Elapsed: 8.039801167s
Sep  5 07:52:24.940: INFO: Pod "exec-volume-test-dynamicpv-jm62": Phase="Pending", Reason="", readiness=false. Elapsed: 10.044722885s
Sep  5 07:52:26.948: INFO: Pod "exec-volume-test-dynamicpv-jm62": Phase="Succeeded", Reason="", readiness=false. Elapsed: 12.052850266s
STEP: Saw pod success
Sep  5 07:52:26.948: INFO: Pod "exec-volume-test-dynamicpv-jm62" satisfied condition "Succeeded or Failed"
Sep  5 07:52:26.954: INFO: Trying to get logs from node k3s-master pod exec-volume-test-dynamicpv-jm62 container exec-container-dynamicpv-jm62: <nil>
STEP: delete the pod
Sep  5 07:52:26.981: INFO: Waiting for pod exec-volume-test-dynamicpv-jm62 to disappear
Sep  5 07:52:26.986: INFO: Pod exec-volume-test-dynamicpv-jm62 no longer exists
STEP: Deleting pod exec-volume-test-dynamicpv-jm62
Sep  5 07:52:26.986: INFO: Deleting pod "exec-volume-test-dynamicpv-jm62" in namespace "volume-2819"
... skipping 14 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":88,"skipped":6942,"failed":0}
SSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSSS
------------------------------
External Storage [Driver: cinder.csi.openstack.org] [Testpattern: Pre-provisioned PV (ext3)] volumes 
  should store data
  test/e2e/storage/testsuites/volumes.go:161
[BeforeEach] [Testpattern: Pre-provisioned PV (ext3)] volumes
... skipping 94 lines ...

    test/e2e/storage/external/external.go:262
------------------------------
SSSSSSSSSSSS
------------------------------
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  5 07:52:37.101: 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
------------------------------
SSSSSSSSSSSSSSSSSSSSSSS
------------------------------
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  5 07:52:37.103: 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 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 4 lines ...
Sep  5 07:52:37.103: INFO: Running Cleanup Action: k8s.io/kubernetes/test/e2e/storage/vsphere.glob..func17.3
Sep  5 07:52:37.103: INFO: Running Cleanup Action: k8s.io/kubernetes/test/e2e/storage/vsphere.glob..func9.2
Sep  5 07:52:37.103: INFO: Running Cleanup Action: k8s.io/kubernetes/test/e2e/storage/vsphere.glob..func4.2
Sep  5 07:52:37.103: INFO: Running Cleanup Action: k8s.io/kubernetes/test/e2e/storage/vsphere.glob..func1.3
Sep  5 07:52:37.103: INFO: Running AfterSuite actions on node 1
Sep  5 07:52:37.103: INFO: Dumping logs locally to: /var/log/csi-pod
Sep  5 07:52:37.104: 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":7145,"failed":0}

Ran 88 of 7233 Specs in 4522.247 seconds
SUCCESS! -- 88 Passed | 0 Failed | 0 Pending | 7145 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.145.133.94] => {
    "changed": false,
    "skip_reason": "Conditional result was False"
}

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

PLAY RECAP *********************************************************************
34.145.133.94              : 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.145.133.94:/var/log/csi-pod/*' /logs/artifacts/logs/
Warning: Permanently added '34.145.133.94' (ECDSA) to the list of known hosts.
+ '[' -z boskos.test-pods.svc.cluster.local ']'
+ python3 tests/scripts/boskos.py --release
... skipping 13 lines ...