2024-05-22 08:53:45.672290 | Job console starting... 2024-05-22 08:53:45.673300 | Updating repositories 2024-05-22 08:53:46.583499 | Preparing job workspace 2024-05-22 08:54:13.901242 | Running Ansible setup... 2024-05-22 08:54:55.179270 | PRE-RUN START: [trusted : services.openstack.netapp.com/netapp-config/playbooks/base/pre.yaml@master] 2024-05-22 08:54:59.530968 | 2024-05-22 08:54:59.531203 | PLAY [localhost] 2024-05-22 08:54:59.637661 | 2024-05-22 08:54:59.637842 | TASK [Gathering Facts] 2024-05-22 08:55:01.008335 | localhost | ok 2024-05-22 08:55:01.179842 | 2024-05-22 08:55:01.180058 | TASK [Setup log path fact] 2024-05-22 08:55:01.452705 | localhost | ok 2024-05-22 08:55:01.559120 | 2024-05-22 08:55:01.559343 | TASK [set-zuul-log-path-fact : Set log path for a change] 2024-05-22 08:55:02.342113 | localhost | ok 2024-05-22 08:55:02.442624 | 2024-05-22 08:55:02.442835 | TASK [set-zuul-log-path-fact : Set log path for a ref update] 2024-05-22 08:55:03.217798 | localhost | skipping: Conditional result was False 2024-05-22 08:55:03.314355 | 2024-05-22 08:55:03.314604 | TASK [set-zuul-log-path-fact : Set log path for a periodic job] 2024-05-22 08:55:04.007601 | localhost | skipping: Conditional result was False 2024-05-22 08:55:04.167646 | 2024-05-22 08:55:04.167891 | TASK [set-zuul-log-path-fact : Set log path for a change] 2024-05-22 08:55:04.327034 | localhost | skipping: Conditional result was False 2024-05-22 08:55:04.475436 | 2024-05-22 08:55:04.475654 | TASK [set-zuul-log-path-fact : Set log path for a ref update] 2024-05-22 08:55:04.710479 | localhost | skipping: Conditional result was False 2024-05-22 08:55:04.813991 | 2024-05-22 08:55:04.814283 | TASK [set-zuul-log-path-fact : Set log path for a periodic job] 2024-05-22 08:55:05.030498 | localhost | skipping: Conditional result was False 2024-05-22 08:55:05.147869 | 2024-05-22 08:55:05.148197 | TASK [emit-job-header : Print job information] 2024-05-22 08:55:05.832905 | # Job Information 2024-05-22 08:55:05.833306 | Ansible Version: 2.9.27 2024-05-22 08:55:05.833422 | Job: manila-tempest-plugin-ontap-dhss 2024-05-22 08:55:05.833525 | Pipeline: upstream-check 2024-05-22 08:55:05.833624 | Executor: managesf.services.openstack.netapp.com 2024-05-22 08:55:05.833722 | Triggered by: https://review.opendev.org/c/openstack/manila/+/918297 2024-05-22 08:55:05.833819 | Event ID: 027e1821e10b4c268f5160cc077a1397 2024-05-22 08:55:05.963380 | 2024-05-22 08:55:05.963645 | LOOP [emit-job-header : Print node information] 2024-05-22 08:55:06.972019 | localhost | ok: 2024-05-22 08:55:06.972333 | localhost | # Node Information 2024-05-22 08:55:06.972412 | localhost | Inventory Hostname: controller 2024-05-22 08:55:06.972484 | localhost | Hostname: ubuntu 2024-05-22 08:55:06.972555 | localhost | Username: zuul 2024-05-22 08:55:06.972623 | localhost | Distro: Ubuntu 22.04 2024-05-22 08:55:06.972690 | localhost | Provider: devstack-22 2024-05-22 08:55:06.972757 | localhost | Label: ubuntu-jammy-functional 2024-05-22 08:55:06.972823 | localhost | Interface IP: ***.***.***.*** 2024-05-22 08:55:07.110020 | 2024-05-22 08:55:07.110226 | TASK [log-inventory : Ensure Zuul Ansible directory exists] 2024-05-22 08:55:08.464420 | localhost -> localhost | changed 2024-05-22 08:55:08.602873 | 2024-05-22 08:55:08.603179 | TASK [log-inventory : Copy ansible inventory to logs dir] 2024-05-22 08:55:10.575935 | localhost -> localhost | changed 2024-05-22 08:55:10.638895 | 2024-05-22 08:55:10.639035 | PLAY [all] 2024-05-22 08:55:10.804298 | 2024-05-22 08:55:10.804505 | TASK [add-build-sshkey : Check to see if ssh key was already created for this build] 2024-05-22 08:55:11.626015 | controller -> localhost | ok 2024-05-22 08:55:12.056879 | 2024-05-22 08:55:12.057053 | TASK [add-build-sshkey : Create a new key in workspace based on build UUID] 2024-05-22 08:55:12.710624 | controller | ok 2024-05-22 08:55:12.964142 | controller | included: /var/lib/zuul/builds/af69b18406584a18bc4f0f7d1e0f54d7/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/create-key-and-replace.yaml 2024-05-22 08:55:13.014878 | 2024-05-22 08:55:13.015170 | TASK [add-build-sshkey : Create Temp SSH key] 2024-05-22 08:55:15.184911 | controller -> localhost | Generating public/private rsa key pair. 2024-05-22 08:55:15.185280 | controller -> localhost | Your identification has been saved in /var/lib/zuul/builds/af69b18406584a18bc4f0f7d1e0f54d7/work/af69b18406584a18bc4f0f7d1e0f54d7_id_rsa. 2024-05-22 08:55:15.185367 | controller -> localhost | Your public key has been saved in /var/lib/zuul/builds/af69b18406584a18bc4f0f7d1e0f54d7/work/af69b18406584a18bc4f0f7d1e0f54d7_id_rsa.pub. 2024-05-22 08:55:15.185444 | controller -> localhost | The key fingerprint is: 2024-05-22 08:55:15.185517 | controller -> localhost | SHA256:gOfXS0Su2wBejsUmCJT5Xbfb+FgbexHtYZyIPs9sTPc zuul-build-sshkey 2024-05-22 08:55:15.185589 | controller -> localhost | The key's randomart image is: 2024-05-22 08:55:15.185661 | controller -> localhost | +---[RSA 3072]----+ 2024-05-22 08:55:15.185747 | controller -> localhost | | .oo . | 2024-05-22 08:55:15.185820 | controller -> localhost | | o. o ..o. | 2024-05-22 08:55:15.185893 | controller -> localhost | | .o.=.=.o.. o..| 2024-05-22 08:55:15.185965 | controller -> localhost | | .+.X +.. ..=.| 2024-05-22 08:55:15.186037 | controller -> localhost | | + S ++ .o.| 2024-05-22 08:55:15.186109 | controller -> localhost | | . =o++....| 2024-05-22 08:55:15.186196 | controller -> localhost | | . o+B+...| 2024-05-22 08:55:15.186270 | controller -> localhost | | . +*. E| 2024-05-22 08:55:15.186343 | controller -> localhost | | .. | 2024-05-22 08:55:15.186415 | controller -> localhost | +----[SHA256]-----+ 2024-05-22 08:55:15.186519 | controller -> localhost | ok: Runtime: 0:00:00.759252 2024-05-22 08:55:15.287251 | 2024-05-22 08:55:15.287466 | TASK [add-build-sshkey : Remote setup ssh keys (linux)] 2024-05-22 08:55:16.081463 | controller | ok 2024-05-22 08:55:16.223737 | controller | included: /var/lib/zuul/builds/af69b18406584a18bc4f0f7d1e0f54d7/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/add-build-sshkey/tasks/remote-linux.yaml 2024-05-22 08:55:16.251233 | 2024-05-22 08:55:16.251393 | TASK [add-build-sshkey : Remove previously added zuul-build-sshkey] 2024-05-22 08:55:16.530545 | controller | skipping: Conditional result was False 2024-05-22 08:55:16.620138 | 2024-05-22 08:55:16.620362 | TASK [add-build-sshkey : Enable access via build key on all nodes] 2024-05-22 08:55:17.723927 | controller | changed 2024-05-22 08:55:17.805854 | 2024-05-22 08:55:17.806036 | TASK [add-build-sshkey : Make sure user has a .ssh] 2024-05-22 08:55:18.208826 | controller | ok 2024-05-22 08:55:18.299058 | 2024-05-22 08:55:18.299251 | TASK [add-build-sshkey : Install build private key as SSH key on all nodes] 2024-05-22 08:55:19.655042 | controller | changed 2024-05-22 08:55:20.879500 | 2024-05-22 08:55:20.879726 | TASK [add-build-sshkey : Install build public key as SSH key on all nodes] 2024-05-22 08:55:22.181405 | controller | changed 2024-05-22 08:55:22.283885 | 2024-05-22 08:55:22.284086 | TASK [add-build-sshkey : Remote setup ssh keys (windows)] 2024-05-22 08:55:23.014217 | controller | skipping: Conditional result was False 2024-05-22 08:55:23.123088 | 2024-05-22 08:55:23.123320 | TASK [remove-zuul-sshkey : Remove master key from local agent] 2024-05-22 08:55:23.821995 | controller -> localhost | changed 2024-05-22 08:55:23.938296 | 2024-05-22 08:55:23.938511 | TASK [add-build-sshkey : Add back temp key] 2024-05-22 08:55:24.909899 | controller -> localhost | Identity added: /var/lib/zuul/builds/af69b18406584a18bc4f0f7d1e0f54d7/work/af69b18406584a18bc4f0f7d1e0f54d7_id_rsa (/var/lib/zuul/builds/af69b18406584a18bc4f0f7d1e0f54d7/work/af69b18406584a18bc4f0f7d1e0f54d7_id_rsa) 2024-05-22 08:55:24.910342 | controller -> localhost | ok: Runtime: 0:00:00.011517 2024-05-22 08:55:24.986466 | 2024-05-22 08:55:24.986673 | TASK [add-build-sshkey : Verify we can still SSH to all nodes] 2024-05-22 08:55:25.886893 | controller | ok 2024-05-22 08:55:25.980874 | 2024-05-22 08:55:25.981075 | TASK [add-build-sshkey : Verify we can still SSH to all nodes (windows)] 2024-05-22 08:55:26.639890 | controller | skipping: Conditional result was False 2024-05-22 08:55:26.728064 | 2024-05-22 08:55:26.728322 | TASK [start-zuul-console : Start zuul_console daemon.] 2024-05-22 08:55:31.665809 | controller | ok 2024-05-22 08:55:31.776152 | 2024-05-22 08:55:31.776440 | LOOP [ensure-output-dirs : Empty Zuul Output directories by removing them] 2024-05-22 08:55:33.293274 | 2024-05-22 08:55:33.293673 | LOOP [ensure-output-dirs : Ensure Zuul Output directories exist] 2024-05-22 08:55:35.075353 | 2024-05-22 08:55:35.075683 | TASK [validate-host : Define zuul_info_dir fact] 2024-05-22 08:55:35.931514 | controller | ok 2024-05-22 08:55:36.074140 | 2024-05-22 08:55:36.074375 | TASK [validate-host : Ensure Zuul Ansible directory exists] 2024-05-22 08:55:37.168496 | controller -> localhost | ok 2024-05-22 08:55:37.308065 | 2024-05-22 08:55:37.308316 | TASK [validate-host : Collect information about the host] 2024-05-22 08:55:38.271619 | controller | ok 2024-05-22 08:55:38.555548 | 2024-05-22 08:55:38.555766 | TASK [validate-host : Sanitize hostname] 2024-05-22 08:55:39.322410 | controller | ok 2024-05-22 08:55:40.010354 | 2024-05-22 08:55:40.010550 | TASK [validate-host : Write out all ansible variables/facts known for each host] 2024-05-22 08:55:41.616455 | controller -> localhost | changed 2024-05-22 08:55:41.733955 | 2024-05-22 08:55:41.734181 | TASK [validate-host : Collect information about zuul worker] 2024-05-22 08:55:43.150283 | controller | ok 2024-05-22 08:55:43.292521 | 2024-05-22 08:55:43.292764 | TASK [validate-host : Write out all zuul information for each host] 2024-05-22 08:55:44.696203 | controller -> localhost | changed 2024-05-22 08:55:44.828744 | 2024-05-22 08:55:44.828940 | LOOP [prepare-workspace-git : Filter zuul projects if sync-only-required-projects flag is set] 2024-05-22 08:55:45.757084 | controller | skipping: Conditional result was False 2024-05-22 08:55:45.757536 | controller | changed: All items complete 2024-05-22 08:55:45.757623 | 2024-05-22 08:55:45.759395 | controller | skipping: Conditional result was False 2024-05-22 08:55:45.761066 | controller | skipping: Conditional result was False 2024-05-22 08:55:45.772611 | controller | skipping: Conditional result was False 2024-05-22 08:55:45.773935 | controller | skipping: Conditional result was False 2024-05-22 08:55:45.775239 | controller | skipping: Conditional result was False 2024-05-22 08:55:45.786789 | controller | skipping: Conditional result was False 2024-05-22 08:55:45.788152 | controller | skipping: Conditional result was False 2024-05-22 08:55:45.789476 | controller | skipping: Conditional result was False 2024-05-22 08:55:45.801060 | controller | skipping: Conditional result was False 2024-05-22 08:55:45.802430 | controller | skipping: Conditional result was False 2024-05-22 08:55:45.803799 | controller | skipping: Conditional result was False 2024-05-22 08:55:45.805047 | controller | skipping: Conditional result was False 2024-05-22 08:55:45.944869 | 2024-05-22 08:55:45.945080 | TASK [prepare-workspace-git : Don't filter zuul projects if flag is false] 2024-05-22 08:55:46.746285 | controller | ok 2024-05-22 08:55:46.899005 | 2024-05-22 08:55:46.899270 | LOOP [prepare-workspace-git : Set initial repo states in workspace] 2024-05-22 08:55:47.862227 | controller | ERROR 2024-05-22 08:55:47.862626 | controller | { 2024-05-22 08:55:47.862706 | controller | "msg": "The task includes an option with an undefined variable. The error was: 'ansible.utils.unsafe_proxy.AnsibleUnsafeText object' has no attribute 'src_dir'\n\nThe error appears to be in '/var/lib/zuul/builds/af69b18406584a18bc4f0f7d1e0f54d7/trusted/project_1/opendev.org/zuul/zuul-jobs/roles/prepare-workspace-git/tasks/main.yaml': line 21, column 3, but may\nbe elsewhere in the file depending on the exact syntax problem.\n\nThe offending line appears to be:\n\n# task startup time we incur.\n- name: Set initial repo states in workspace\n ^ here\n" 2024-05-22 08:55:47.862781 | controller | } 2024-05-22 08:55:47.967985 | 2024-05-22 08:55:47.968316 | PLAY RECAP 2024-05-22 08:55:47.968571 | controller | ok: 22 changed: 9 unreachable: 0 failed: 1 skipped: 4 rescued: 0 ignored: 0 2024-05-22 08:55:47.968762 | localhost | ok: 6 changed: 2 unreachable: 0 failed: 0 skipped: 5 rescued: 0 ignored: 0 2024-05-22 08:55:47.968913 | 2024-05-22 08:55:48.662656 | PRE-RUN END RESULT_NORMAL: [trusted : services.openstack.netapp.com/netapp-config/playbooks/base/pre.yaml@master] 2024-05-22 08:55:48.805961 | POST-RUN START: [untrusted : services.openstack.netapp.com/netapp-jobs/playbooks/netapp/manila-tempest-plugin-ontap-dhss/post.yaml@master] 2024-05-22 08:55:51.613937 | 2024-05-22 08:55:51.614249 | PLAY [all] 2024-05-22 08:55:51.754881 | 2024-05-22 08:55:51.755130 | TASK [Execute teradown-manila-ss to unlock the device.] 2024-05-22 08:56:02.863288 | controller | MODULE FAILURE: 2024-05-22 08:56:02.863676 | controller | Traceback (most recent call last): 2024-05-22 08:56:02.863777 | controller | File "", line 102, in 2024-05-22 08:56:02.863860 | controller | File "", line 94, in _ansiballz_main 2024-05-22 08:56:02.863940 | controller | File "", line 40, in invoke_module 2024-05-22 08:56:02.864020 | controller | File "/usr/lib/python3.10/runpy.py", line 224, in run_module 2024-05-22 08:56:02.864099 | controller | return _run_module_code(code, init_globals, run_name, mod_spec) 2024-05-22 08:56:02.864198 | controller | File "/usr/lib/python3.10/runpy.py", line 96, in _run_module_code 2024-05-22 08:56:02.864278 | controller | _run_code(code, mod_globals, init_globals, 2024-05-22 08:56:02.864357 | controller | File "/usr/lib/python3.10/runpy.py", line 86, in _run_code 2024-05-22 08:56:02.864435 | controller | exec(code, run_globals) 2024-05-22 08:56:02.864514 | controller | File "/tmp/ansible_command_payload_73j_15m3/ansible_command_payload.zip/ansible/modules/command.py", line 675, in 2024-05-22 08:56:02.864593 | controller | File "/tmp/ansible_command_payload_73j_15m3/ansible_command_payload.zip/ansible/modules/command.py", line 620, in main 2024-05-22 08:56:02.864671 | controller | FileNotFoundError: [Errno 2] No such file or directory: '/home/zuul/netapp-jobs/playbooks/netapp/manila-tempest-plugin-ontap-dhss/nested' 2024-05-22 08:56:03.077821 | 2024-05-22 08:56:03.078116 | PLAY RECAP 2024-05-22 08:56:03.078360 | controller | ok: 0 changed: 0 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0 2024-05-22 08:56:03.078509 | 2024-05-22 08:56:03.647510 | POST-RUN END RESULT_NORMAL: [untrusted : services.openstack.netapp.com/netapp-jobs/playbooks/netapp/manila-tempest-plugin-ontap-dhss/post.yaml@master] 2024-05-22 08:56:03.780705 | POST-RUN START: [untrusted : services.openstack.netapp.com/netapp-jobs/playbooks/opendev/openstack/tempest/post-tempest.yaml@master] 2024-05-22 08:56:06.668375 | 2024-05-22 08:56:06.668562 | PLAY [tempest] 2024-05-22 08:56:06.786496 | 2024-05-22 08:56:06.786713 | TASK [fetch-subunit-output : Find stestr or testr executable] 2024-05-22 08:56:07.822689 | controller | changed: non-zero return code 2024-05-22 08:56:08.002733 | 2024-05-22 08:56:08.002970 | TASK [fetch-subunit-output : Get the list of directories with subunit files] 2024-05-22 08:56:08.691265 | controller | skipping: Conditional result was False 2024-05-22 08:56:08.850800 | 2024-05-22 08:56:08.851053 | LOOP [fetch-subunit-output : Find any inflight partial subunit files] 2024-05-22 08:56:09.691290 | 2024-05-22 08:56:09.691592 | LOOP [fetch-subunit-output : Copy any inflight subunit files] 2024-05-22 08:56:10.492360 | 2024-05-22 08:56:10.492631 | TASK [fetch-subunit-output : Create a temporary file to store the subunit stream] 2024-05-22 08:56:11.058103 | controller | skipping: Conditional result was False 2024-05-22 08:56:11.138789 | 2024-05-22 08:56:11.139004 | LOOP [fetch-subunit-output : Generate subunit file] 2024-05-22 08:56:11.828544 | 2024-05-22 08:56:11.828872 | TASK [fetch-subunit-output : Copy the combined subunit file to the zuul work directory] 2024-05-22 08:56:12.381457 | controller | skipping: Conditional result was False 2024-05-22 08:56:12.510798 | 2024-05-22 08:56:12.511022 | TASK [fetch-subunit-output : Remove the temporary file] 2024-05-22 08:56:13.201970 | controller | skipping: Conditional result was False 2024-05-22 08:56:13.337903 | 2024-05-22 08:56:13.338225 | TASK [fetch-subunit-output : Process and fetch subunit results] 2024-05-22 08:56:14.106013 | controller | skipping: Conditional result was False 2024-05-22 08:56:14.193031 | 2024-05-22 08:56:14.193326 | TASK [process-stackviz : Devstack checks if stackviz archive exists] 2024-05-22 08:56:14.917223 | controller | ok 2024-05-22 08:56:15.052544 | 2024-05-22 08:56:15.052748 | TASK [process-stackviz : debug] 2024-05-22 08:56:15.725890 | controller | skipping: Conditional result was False 2024-05-22 08:56:15.841009 | 2024-05-22 08:56:15.841233 | TASK [process-stackviz : Check if subunit data exists] 2024-05-22 08:56:16.887854 | controller | ok 2024-05-22 08:56:17.040029 | 2024-05-22 08:56:17.040312 | TASK [process-stackviz : debug] 2024-05-22 08:56:17.873846 | Subunit file could not be found at /opt/stack/tempest/testrepository.subunit 2024-05-22 08:56:17.986196 | 2024-05-22 08:56:17.986459 | TASK [include_role : ensure-pip] 2024-05-22 08:56:18.899155 | controller | skipping: Conditional result was False 2024-05-22 08:56:19.038138 | 2024-05-22 08:56:19.038415 | TASK [process-stackviz : pip] 2024-05-22 08:56:20.027118 | controller | skipping: Conditional result was False 2024-05-22 08:56:20.122451 | 2024-05-22 08:56:20.122687 | TASK [process-stackviz : Deploy stackviz static html+js] 2024-05-22 08:56:20.996843 | controller | skipping: Conditional result was False 2024-05-22 08:56:21.125072 | 2024-05-22 08:56:21.125415 | TASK [process-stackviz : Check if dstat data exists] 2024-05-22 08:56:21.931444 | controller | skipping: Conditional result was False 2024-05-22 08:56:22.400834 | 2024-05-22 08:56:22.401081 | TASK [process-stackviz : Run stackviz with dstat] 2024-05-22 08:56:23.234998 | controller | skipping: Conditional result was False 2024-05-22 08:56:23.326311 | 2024-05-22 08:56:23.326494 | TASK [process-stackviz : Run stackviz without dstat] 2024-05-22 08:56:24.062091 | controller | skipping: Conditional result was False 2024-05-22 08:56:24.191154 | 2024-05-22 08:56:24.191379 | PLAY RECAP 2024-05-22 08:56:24.191522 | controller | ok: 4 changed: 1 unreachable: 0 failed: 0 skipped: 15 rescued: 0 ignored: 0 2024-05-22 08:56:24.191610 | 2024-05-22 08:56:24.733310 | POST-RUN END RESULT_NORMAL: [untrusted : services.openstack.netapp.com/netapp-jobs/playbooks/opendev/openstack/tempest/post-tempest.yaml@master] 2024-05-22 08:56:24.876695 | POST-RUN START: [untrusted : services.openstack.netapp.com/netapp-jobs/playbooks/opendev/openstack/devstack/post.yaml@master] 2024-05-22 08:56:28.068055 | 2024-05-22 08:56:28.068415 | PLAY [all] 2024-05-22 08:56:28.735006 | 2024-05-22 08:56:28.735282 | TASK [export-devstack-journal : Ensure /home/zuul/logs exists] 2024-05-22 08:56:29.491515 | controller | changed 2024-05-22 08:56:30.095451 | 2024-05-22 08:56:30.095719 | TASK [export-devstack-journal : Export legacy stack screen log files] 2024-05-22 08:56:31.679664 | controller | ok: Runtime: 0:00:00.734302 2024-05-22 08:56:31.821402 | 2024-05-22 08:56:31.821666 | TASK [export-devstack-journal : Export legacy syslog.txt] 2024-05-22 11:56:32.344179 | controller | cat: /opt/stack/log-start-timestamp.txt: No such file or directory 2024-05-22 11:56:32.352751 | controller | Failed to parse timestamp: 2024-05-22 08:56:32.418206 | controller | ERROR 2024-05-22 08:56:32.418539 | controller | { 2024-05-22 08:56:32.418636 | controller | "delta": "0:00:00.014686", 2024-05-22 08:56:32.418729 | controller | "end": "2024-05-22 11:56:32.353902", 2024-05-22 08:56:32.418813 | controller | "msg": "non-zero return code", 2024-05-22 08:56:32.418893 | controller | "rc": 1, 2024-05-22 08:56:32.418974 | controller | "start": "2024-05-22 11:56:32.339216" 2024-05-22 08:56:32.419053 | controller | } 2024-05-22 08:56:32.539808 | 2024-05-22 08:56:32.540004 | PLAY RECAP 2024-05-22 08:56:32.540154 | controller | ok: 2 changed: 2 unreachable: 0 failed: 1 skipped: 0 rescued: 0 ignored: 0 2024-05-22 08:56:32.540248 | 2024-05-22 08:56:33.262409 | POST-RUN END RESULT_NORMAL: [untrusted : services.openstack.netapp.com/netapp-jobs/playbooks/opendev/openstack/devstack/post.yaml@master] 2024-05-22 08:56:33.388284 | POST-RUN START: [trusted : services.openstack.netapp.com/netapp-config/playbooks/base/post.yaml@master] 2024-05-22 08:56:36.160250 | 2024-05-22 08:56:36.160543 | PLAY [all] 2024-05-22 08:56:36.292237 | 2024-05-22 08:56:36.292447 | TASK [fetch-output : Set log path for multiple nodes] 2024-05-22 08:56:37.053376 | controller | skipping: Conditional result was False 2024-05-22 08:56:37.212027 | 2024-05-22 08:56:37.212263 | TASK [fetch-output : Set log path for single node] 2024-05-22 08:56:37.992032 | controller | ok 2024-05-22 08:56:38.536358 | 2024-05-22 08:56:38.536768 | LOOP [fetch-output : Ensure local output dirs] 2024-05-22 08:56:40.008803 | 2024-05-22 08:56:40.009212 | LOOP [fetch-output : Collect logs, artifacts and docs] 2024-05-22 08:56:41.500031 | controller | changed: .d..t...... ./ 2024-05-22 08:56:41.500491 | controller | changed: All items complete 2024-05-22 08:56:41.500608 | 2024-05-22 08:56:42.249945 | controller | changed: .d..t...... ./ 2024-05-22 08:56:43.090119 | controller | changed: .d..t...... ./ 2024-05-22 08:56:43.267703 | 2024-05-22 08:56:43.267988 | LOOP [merge-output-to-logs : Move artifacts and docs to logs dir] 2024-05-22 08:56:44.555822 | 2024-05-22 08:56:44.556090 | TASK [remove-build-sshkey : Remove the build SSH key from all nodes] 2024-05-22 08:56:45.281351 | controller | changed 2024-05-22 08:56:45.415324 | 2024-05-22 08:56:45.415503 | PLAY [localhost] 2024-05-22 08:56:45.912339 | 2024-05-22 08:56:45.912622 | TASK [add-fileserver : Create SSH private key tempfile] 2024-05-22 08:56:46.559193 | localhost | changed 2024-05-22 08:56:46.716868 | 2024-05-22 08:56:46.717054 | TASK [add-fileserver : Create SSH private key from secret] 2024-05-22 08:56:48.096103 | localhost | changed 2024-05-22 08:56:48.218623 | 2024-05-22 08:56:48.218841 | TASK [add-fileserver : Add fileserver ssh key] 2024-05-22 08:56:48.707643 | localhost | Identity added: /var/lib/zuul/builds/af69b18406584a18bc4f0f7d1e0f54d7/work/tmp/ansible.ob3462zx (/var/lib/zuul/builds/af69b18406584a18bc4f0f7d1e0f54d7/work/tmp/ansible.ob3462zx) 2024-05-22 08:56:48.708008 | localhost | ok: Runtime: 0:00:00.009475 2024-05-22 08:56:48.883574 | 2024-05-22 08:56:48.883856 | TASK [add-fileserver : Remove SSH private key from disk] 2024-05-22 08:56:49.465438 | localhost | ok: Runtime: 0:00:00.003689 2024-05-22 08:56:49.600839 | 2024-05-22 08:56:49.601082 | TASK [add-fileserver : Add fileserver to inventory] 2024-05-22 08:56:49.812830 | localhost | changed 2024-05-22 08:56:49.947224 | 2024-05-22 08:56:49.947478 | TASK [add-fileserver : Add fileserver server to known hosts] 2024-05-22 08:56:50.697022 | localhost | changed 2024-05-22 08:56:50.810134 | 2024-05-22 08:56:50.810360 | TASK [generate-zuul-manifest : Generate Zuul manifest] 2024-05-22 08:56:51.552833 | localhost | changed 2024-05-22 08:56:51.678935 | 2024-05-22 08:56:51.679149 | TASK [generate-zuul-manifest : Return Zuul manifest URL to Zuul] 2024-05-22 08:56:51.904939 | localhost | ok 2024-05-22 08:56:52.024862 | 2024-05-22 08:56:52.025069 | PLAY [services.openstack.netapp.com] 2024-05-22 08:56:52.314249 | 2024-05-22 08:56:52.314571 | TASK [Set zuul-log-path fact] 2024-05-22 08:56:52.561990 | services.openstack.netapp.com | ok 2024-05-22 08:56:52.739403 | 2024-05-22 08:56:52.739687 | TASK [set-zuul-log-path-fact : Set log path for a change] 2024-05-22 08:56:53.075097 | services.openstack.netapp.com | ok 2024-05-22 08:56:53.198728 | 2024-05-22 08:56:53.198954 | TASK [set-zuul-log-path-fact : Set log path for a ref update] 2024-05-22 08:56:53.415648 | services.openstack.netapp.com | skipping: Conditional result was False 2024-05-22 08:56:53.497348 | 2024-05-22 08:56:53.497591 | TASK [set-zuul-log-path-fact : Set log path for a periodic job] 2024-05-22 08:56:53.694736 | services.openstack.netapp.com | skipping: Conditional result was False 2024-05-22 08:56:53.808163 | 2024-05-22 08:56:53.808398 | TASK [set-zuul-log-path-fact : Set log path for a change] 2024-05-22 08:56:54.051088 | services.openstack.netapp.com | skipping: Conditional result was False 2024-05-22 08:56:54.144305 | 2024-05-22 08:56:54.144518 | TASK [set-zuul-log-path-fact : Set log path for a ref update] 2024-05-22 08:56:54.347736 | services.openstack.netapp.com | skipping: Conditional result was False 2024-05-22 08:56:54.440000 | 2024-05-22 08:56:54.440216 | TASK [set-zuul-log-path-fact : Set log path for a periodic job] 2024-05-22 08:56:54.659253 | services.openstack.netapp.com | skipping: Conditional result was False 2024-05-22 08:56:54.798501 | 2024-05-22 08:56:54.798798 | TASK [upload-logs : Create log directories] 2024-05-22 08:56:55.733587 | services.openstack.netapp.com | changed 2024-05-22 08:56:55.821441 | 2024-05-22 08:56:55.821666 | TASK [upload-logs : Ensure logs are readable before uploading] 2024-05-22 08:56:56.306910 | services.openstack.netapp.com -> localhost | ok: Runtime: 0:00:00.003856 2024-05-22 08:56:56.403341 | 2024-05-22 08:56:56.403549 | TASK [upload-logs : Upload logs to log server] 2024-05-22 08:56:57.841224 | services.openstack.netapp.com | Output suppressed because no_log was given 2024-05-22 08:56:58.090060 | 2024-05-22 08:56:58.090362 | LOOP [upload-logs : Compress console log and json output] 2024-05-22 08:56:58.296715 | services.openstack.netapp.com | skipping: Conditional result was False 2024-05-22 08:56:58.297332 | services.openstack.netapp.com | changed: All items complete 2024-05-22 08:56:58.297437 | 2024-05-22 08:56:58.309309 | services.openstack.netapp.com | skipping: Conditional result was False 2024-05-22 08:56:58.386329 | 2024-05-22 08:56:58.386538 | LOOP [upload-logs : Upload compressed console log and json output] 2024-05-22 08:56:58.537083 | services.openstack.netapp.com | skipping: Conditional result was False 2024-05-22 08:56:58.537816 | 2024-05-22 08:56:58.549451 | services.openstack.netapp.com | skipping: Conditional result was False 2024-05-22 08:56:58.614580 | 2024-05-22 08:56:58.614791 | LOOP [upload-logs : Upload console log and json output] 2024-05-22 08:56:59.649875 | services.openstack.netapp.com | changed: