NFV vim alarm thread sometimes stalls on init

Bug #1925697 reported by Al Bailey
6
This bug affects 1 person
Affects Status Importance Assigned to Milestone
StarlingX
Fix Released
Medium
Al Bailey

Bug Description

There is a random issue where the VIM sometimes will start up and its event and alarm thread (sub process) will appear to be stalled.
This happens maybe once out of every hundred restarts.

Through instrumenting the code, it appears to be during the debug logger setup
Will provide a fix.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to nfv (master)

Fix proposed to branch: master
Review: https://review.opendev.org/c/starlingx/nfv/+/787651

Changed in starlingx:
status: New → In Progress
Al Bailey (albailey1974)
Changed in starlingx:
assignee: nobody → Al Bailey (albailey1974)
Revision history for this message
Ghada Khalil (gkhalil) wrote :

screening: low priority / not gating; highly intermittent issue

Changed in starlingx:
importance: Undecided → Low
tags: added: stx.nfv
Revision history for this message
Al Bailey (albailey1974) wrote :

There is a second way the vim alarm thread can stall. Updated that review to be partial-fix. Will investigate the second case, which consistently shows this log pattern

2021-04-22T00:57:15.274 controller-0 VIM_Thread[1722206] INFO vim.py.172 Started
2021-04-22T00:57:16.669 controller-0 VIM_Thread[1722206] INFO _dor_module.py.137 DOR completed.
2021-04-22T00:57:35.887 controller-0 VIM_Thread[1722206] INFO _task_worker_pool.py.73 Timeout worker Identity-Worker-0
2021-04-22T00:57:36.895 controller-0 VIM_Thread[1722206] ERROR _task.py.200 Task(get_tenants) work (get_token) timed out, id=3.
2021-04-22T00:57:36.896 controller-0 VIM_Thread[1722206] ERROR _vim_nfvi_audits.py.318 Audit-Tenants callback, not completed, responses={'completed': False, 'reason': ''}.
2021-04-22T00:57:45.431 controller-0 VIM_Thread[1722206] INFO _sw_patch.py.196 Audit alarms, timer_id=6.
2021-04-22T00:57:47.639 controller-0 VIM_Thread[1722206] INFO _sw_patch.py.205 Audit software patch hosts, timer_id=6.
2021-04-22T00:58:15.114 controller-0 VIM_Thread[1722206] ERROR _thread.py.100 Thread Event-Log stalled, progress_marker=0, elapsed_secs=0.
2021-04-22T00:58:15.115 controller-0 VIM_Thread[1722206] ERROR _thread.py.100 Thread Alarm stalled, progress_marker=0, elapsed_secs=0.

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to nfv (master)

Reviewed: https://review.opendev.org/c/starlingx/nfv/+/787651
Committed: https://opendev.org/starlingx/nfv/commit/4ffec12dc88cf43dbf86620193020be30bde33d6
Submitter: "Zuul (22348)"
Branch: master

commit 4ffec12dc88cf43dbf86620193020be30bde33d6
Author: albailey <email address hidden>
Date: Thu Apr 22 18:15:01 2021 -0500

    Add missing debug logger entries for VIM

    The debug loggers are pre-created during process startup,
    and any that are missing can be created using lazy init.

    However the lazy init is not multi process safe and can
    lead to a subprocess deadlock during the import phase, which
    produces no logs or evidence that the thread is stalled.

    The workaround at the moment is to ensure that all the debug
    loggers defined at import time are configured to be setup when
    the process is created.

    There is still another cause of a stall. A separate commit
    will address it.

    Partial-Bug: 1925697
    Signed-off-by: albailey <email address hidden>
    Change-Id: I90436c1bd063a634ab8a1496236a78b01a04d51a

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to nfv (r/stx.5.0)

Fix proposed to branch: r/stx.5.0
Review: https://review.opendev.org/c/starlingx/nfv/+/788759

Revision history for this message
Al Bailey (albailey1974) wrote :

Addressing the logger initialization issue resolves the stall. Setting this as fixed.

Changed in starlingx:
status: In Progress → Fix Committed
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to nfv (r/stx.5.0)

Reviewed: https://review.opendev.org/c/starlingx/nfv/+/788759
Committed: https://opendev.org/starlingx/nfv/commit/1d7e5be68aa1d8aa167244411d1828bfc3e3d787
Submitter: "Zuul (22348)"
Branch: r/stx.5.0

commit 1d7e5be68aa1d8aa167244411d1828bfc3e3d787
Author: albailey <email address hidden>
Date: Thu Apr 22 18:15:01 2021 -0500

    Add missing debug logger entries for VIM

    The debug loggers are pre-created during process startup,
    and any that are missing can be created using lazy init.

    However the lazy init is not multi process safe and can
    lead to a subprocess deadlock during the import phase, which
    produces no logs or evidence that the thread is stalled.

    The workaround at the moment is to ensure that all the debug
    loggers defined at import time are configured to be setup when
    the process is created.

    There is still another cause of a stall. A separate commit
    will address it.

    Partial-Bug: 1925697
    Signed-off-by: albailey <email address hidden>
    Change-Id: I90436c1bd063a634ab8a1496236a78b01a04d51a
    (cherry picked from commit 4ffec12dc88cf43dbf86620193020be30bde33d6)

Ghada Khalil (gkhalil)
Changed in starlingx:
status: Fix Committed → Fix Released
Revision history for this message
Ghada Khalil (gkhalil) wrote :

Added the stx.5.0 release tag since the developer cherrypicked this to the r/stx.5.0 branch

Changed in starlingx:
importance: Low → Medium
tags: added: stx.5.0
Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to nfv (f/centos8)

Fix proposed to branch: f/centos8
Review: https://review.opendev.org/c/starlingx/nfv/+/792239

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Change abandoned on nfv (f/centos8)

Change abandoned by "Chuck Short <email address hidden>" on branch: f/centos8
Review: https://review.opendev.org/c/starlingx/nfv/+/792239

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix proposed to nfv (f/centos8)

Fix proposed to branch: f/centos8
Review: https://review.opendev.org/c/starlingx/nfv/+/796295

Revision history for this message
OpenStack Infra (hudson-openstack) wrote :

Fix proposed to branch: f/centos8
Review: https://review.opendev.org/c/starlingx/nfv/+/796327

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Change abandoned on nfv (f/centos8)

Change abandoned by "Chuck Short <email address hidden>" on branch: f/centos8
Review: https://review.opendev.org/c/starlingx/nfv/+/796295

Revision history for this message
OpenStack Infra (hudson-openstack) wrote : Fix merged to nfv (f/centos8)
Download full text (14.5 KiB)

Reviewed: https://review.opendev.org/c/starlingx/nfv/+/796327
Committed: https://opendev.org/starlingx/nfv/commit/96fa4281d73e701e58388228c8e8e85491785c38
Submitter: "Zuul (22348)"
Branch: f/centos8

commit 73c683d5337beff6062b40f011f3b775f3c70107
Author: Eric MacDonald <email address hidden>
Date: Fri May 21 17:25:38 2021 -0400

    Update fw-update-strategy steps to load wait_time from_dict

    The sw-manager fw-update-strategy feature is seen
    to fail in a traceback.

    The __wait_time member of the FwUpdateHostsStep and
    FwUpdateAbortHostsStep objects are not de-serialized
    from the DB using the ‘from_dict’ methods. This means
    it does not run the ‘init’ method for those classes,
    but instead attempts to re-constitute the object
    directly which can lead to an exception\traceback.

    This update adds the _wait_time member to each of these
    fw-update-strategy class objects' 'from_dict' function.

    This update also removes another object member, this one
    currently unused, that would also not be de-serialized
    if it were to be put to use as is in the future.

    Test Plan:

    PASS: Verify end-to-end orchestrated fw update (x2)

    Closes-Bug: 1929251
    Change-Id: I4540d1712f4dfee74e592c4f3ebce9c7cc913ab2
    Signed-off-by: Eric MacDonald <email address hidden>

commit 5ff24cf13f9d8cacab9ec15ff193fc8c819d31f4
Author: albailey <email address hidden>
Date: Fri May 21 17:51:38 2021 -0500

    Specify the nodeset for zuul jobs

    The py2.7 jobs need to specify xenial
    Changed py37 to py36 and specify bionic.

    The un-specified python3 jobs work fine on either
    focal or bionic.

    zuul is not setup to trigger off code changes in this repo
    so no source code changes are required to trigger the zuul
    jobs

    Partial-Bug: 1928978
    Signed-off-by: albailey <email address hidden>
    Change-Id: Iab9c8727a0f16fa7ff02c20ca3bec5622abe7bd7

commit 98d66c7f3bc46e1a990907db1c8f498f9841c885
Author: albailey <email address hidden>
Date: Thu May 6 12:03:15 2021 -0500

    Fix swact issue when deserializing an old patch strategy

    If a patch strategy in a previous release is de-serialized
    in the vim running a load that contains this commit
    https://review.opendev.org/c/starlingx/nfv/+/780310

    the vim would fail to startup due to key errors as it
    expected fields that did not exist in the previous release.

    Closes-Bug: 1927526
    Signed-off-by: albailey <email address hidden>
    Change-Id: Ia72463feb50f7d6a2491242ec865f7c854c75419

commit e5856549e51f10ae6818ec1d0ec43568225e9bd9
Author: albailey <email address hidden>
Date: Thu May 6 12:46:29 2021 -0500

    Increase the patching apply_patch REST API timeout

    During a kubernetes upgrade orchestration, the kubernetes
    patch needs to be applied. The default timeout was 20 seconds
    but a lab took 24 seconds.

    Thi update increases the timeout for that API call.

    Closes-Bug: 1927532
    Signed-off-by: albailey <email address hidden>
    Change-Id: I63a6c5616f6abf7a5b6879e5ebd458a8ecc52ba7

commit 4ffec1...

tags: added: in-f-centos8
To post a comment you must log in.
This report contains Public information  
Everyone can see this information.

Other bug subscribers

Remote bug watches

Bug watches keep track of this bug in other bug trackers.