Loading...

Type: Bug
Resolution: Unresolved
Priority: Normal
Fix Version/s: rhos-18.0.4
Affects Version/s: None
Component/s: test-operator
Labels:
None

Story Points:
4
Epic Link:
Test-operator 2024Q4 targets
Blocked:
False
Blocked Reason:

Hide

None

Show
None
Ready:
False
Dev Approval:
?
Docs Approval:
?
PM Approval:
?
QE Approval:
?
Regression:
None
Intelligence Requested:
Market:

Sprint:
Sprint 104
Severity:
Important

SFDC Cases Counter:
SFDC Cases Open:
SFDC Cases Links:

This is similar to ~~OSPRH-8837~~. With that bug, the issue was often reproduced and it seems now it occurs with much less frequency.

The new bug has been reproduced on a BGP integration job:
https://sf.hosted.upshift.rdu2.redhat.com/logs/openstack-bgp-jobs-periodic-integration-rhoso18.0-rhel9/gitlab.cee.redhat.com/ci-framework/ci-framework-jobs/main/bgpdt02-rhel9-rhoso18.0/4dff5a8/logs/controller-0/ci-framework-data/tests/test_operator/

The job didn't save os-must-gather logs, but I will attach some logs to this ticket.

The following logs show that the step-1 pod was run after last step (step-4). This is a problem because step-1 has to create Openstack resources that are reused at step-4.

[zuul@controller-0 ~]$ oc -n openstack logs tobiko-tests-sanity-before-faults-workflow-step-0-wjsc9 |  grep "Execute:"
tools.common: INFO    2024-09-26 11:33:41,081 | Execute: ['/bin/bash', '-x', '-c', 'env | sort >> "/var/lib/tobiko/tobiko/.tox/sanity/log/tobiko_results_sanity.log"']
tools.common: INFO    2024-09-26 11:33:41,090 | Execute: ['/bin/bash', '-x', '-c', "pytest -v --numprocesses 'auto' --dist loadscope   --log-file=/var/lib/tobiko/tobiko/.tox/sanity/log/tobiko_results_sanity.log --junitxml=/var/lib/tobiko/tobiko/.tox/sanity/log/tobiko_results_sanity.xml --html=/var/lib/tobiko/tobiko/.tox/sanity/log/tobiko_results_sanity.html --self-contained-html /var/lib/tobiko/tobiko/tobiko/tests/sanity"]
[zuul@controller-0 ~]$ oc -n openstack logs tobiko-tests-create-resources-workflow-step-1-lb58s |  grep "Execute:"
tools.common: INFO    2024-09-26 11:51:51,195 | Execute: ['/bin/bash', '-x', '-c', 'env | sort >> "/var/lib/tobiko/tobiko/.tox/scenario/log/tobiko_results_scenario.log"']
tools.common: INFO    2024-09-26 11:51:51,205 | Execute: ['/bin/bash', '-x', '-c', "pytest -v --numprocesses 'auto' --dist loadscope   --log-file=/var/lib/tobiko/tobiko/.tox/scenario/log/tobiko_results_scenario.log --junitxml=/var/lib/tobiko/tobiko/.tox/scenario/log/tobiko_results_scenario.xml --html=/var/lib/tobiko/tobiko/.tox/scenario/log/tobiko_results_scenario.html --self-contained-html /var/lib/tobiko/tobiko/tobiko/tests/scenario"]
[zuul@controller-0 ~]$ oc -n openstack logs tobiko-tests-neutron-faults-workflow-step-2-s2vdv |  grep "Execute:"
tools.common: INFO    2024-09-26 11:37:32,870 | Execute: ['/bin/bash', '-x', '-c', 'env | sort >> "/var/lib/tobiko/tobiko/.tox/neutron_faults/log/tobiko_results_neutron_faults.log"']
tools.common: INFO    2024-09-26 11:37:32,881 | Execute: ['/bin/bash', '-x', '-c', 'pytest -v    --log-file=/var/lib/tobiko/tobiko/.tox/neutron_faults/log/tobiko_results_neutron_faults.log --junitxml=/var/lib/tobiko/tobiko/.tox/neutron_faults/log/tobiko_results_neutron_faults.xml --html=/var/lib/tobiko/tobiko/.tox/neutron_faults/log/tobiko_results_neutron_faults.html --self-contained-html /var/lib/tobiko/tobiko/tobiko/tests/faults/neutron']
[zuul@controller-0 ~]$ oc -n openstack logs tobiko-tests-sanity-after-faults-workflow-step-3-4c4c7 |  grep "Execute:"
tools.common: INFO    2024-09-26 11:44:31,826 | Execute: ['/bin/bash', '-x', '-c', 'env | sort >> "/var/lib/tobiko/tobiko/.tox/sanity/log/tobiko_results_sanity.log"']
tools.common: INFO    2024-09-26 11:44:31,835 | Execute: ['/bin/bash', '-x', '-c', "pytest -v --numprocesses 'auto' --dist loadscope   --log-file=/var/lib/tobiko/tobiko/.tox/sanity/log/tobiko_results_sanity.log --junitxml=/var/lib/tobiko/tobiko/.tox/sanity/log/tobiko_results_sanity.xml --html=/var/lib/tobiko/tobiko/.tox/sanity/log/tobiko_results_sanity.html --self-contained-html /var/lib/tobiko/tobiko/tobiko/tests/sanity"]
[zuul@controller-0 ~]$ oc -n openstack logs tobiko-tests-verify-resources-workflow-step-4-m2q72 |  grep "Execute:"
tools.common: INFO    2024-09-26 11:47:46,867 | Execute: ['/bin/bash', '-x', '-c', 'env | sort >> "/var/lib/tobiko/tobiko/.tox/scenario/log/tobiko_results_scenario.log"']
tools.common: INFO    2024-09-26 11:47:46,876 | Execute: ['/bin/bash', '-x', '-c', "pytest -v --numprocesses 'auto' --dist loadscope   --log-file=/var/lib/tobiko/tobiko/.tox/scenario/log/tobiko_results_scenario.log --junitxml=/var/lib/tobiko/tobiko/.tox/scenario/log/tobiko_results_scenario.xml --html=/var/lib/tobiko/tobiko/.tox/scenario/log/tobiko_results_scenario.html --self-contained-html /var/lib/tobiko/tobiko/tobiko/tests/scenario"]

The test-operator controller manager logs show that there was an issue with the PVC when the step-1 pod was going to be created.

[zuul@controller-0 ~]$ oc -n openstack logs test-operator-controller-manager-78b5cf5695-cfqml | grep ERROR -A7 -B1
2024-09-26T11:30:58Z    INFO    Controllers.Tempest     Job completed   {"controller": "tempest", "controllerGroup": "test.openstack.org", "controllerKind": "Tempest", "Tempest": {"name":"tempest-tests","namespace":"openstack"}, "namespace": "openstack", "name": "tempest-tests", "reconcileID": "8103d414-9b80-4628-baa0-cdb81443ee01"}
2024-09-26T11:31:27Z    ERROR   Reconciler error        {"controller": "tobiko", "controllerGroup": "test.openstack.org", "controllerKind": "Tobiko", "Tobiko": {"name":"tobiko-tests","namespace":"openstack"}, "namespace": "openstack", "name": "tobiko-tests", "reconcileID": "add297fc-fc81-4d83-b852-50dd71a2adcd", "error": "PersistentVolumeClaim \"tobiko-tests-ebb36\" not found"}
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).reconcileHandler
        /remote-source/deps/gomod/pkg/mod/sigs.k8s.io/controller-runtime@v0.16.6/pkg/internal/controller/controller.go:329
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).processNextWorkItem
        /remote-source/deps/gomod/pkg/mod/sigs.k8s.io/controller-runtime@v0.16.6/pkg/internal/controller/controller.go:266
sigs.k8s.io/controller-runtime/pkg/internal/controller.(*Controller).Start.func2.2
        /remote-source/deps/gomod/pkg/mod/sigs.k8s.io/controller-runtime@v0.16.6/pkg/internal/controller/controller.go:227
2024-09-26T11:31:27Z    INFO    Controllers.Tobiko      Lock acquired   {"controller": "tobiko", "controllerGroup": "test.openstack.org", "controllerKind": "Tobiko", "Tobiko": {"name":"tobiko-tests","namespace":"openstack"}, "namespace": "openstack", "name": "tobiko-tests", "reconcileID": "627ba4be-a7c4-4160-93f6-d44a34329fec"}

When the tobiko execution ended, the status of PVC was apparently correctL

[zuul@controller-0 ~]$ oc -n openstack get pvc | grep ebb36
tobiko-tests-ebb36                           Bound    local-storage01-worker-3   10Gi       RWO,ROX,RWX    local-storage   <unset>                 162m
[zuul@controller-0 ~]$ oc -n openstack get pv | grep ebb36
local-storage01-worker-3   10Gi       RWO,ROX,RWX    Delete           Bound       openstack/tobiko-tests-ebb36                           local-storage   <unset>                          5h51m

relates to

OSPRH-9243 Issue when copying logs from a workflow step