Menu

#3400 amf: inconsistent logging when removing SI during opensaf stopping

5.27.01
fixed
None
enhancement
amf
nd
5
minor
False
2026-07-02
2026-06-16
No

Deploy amf demo on the cluster. Stop opensafd service via systemctl. Log printed in syslog

2026-06-16 01:49:27.997 SC-1 systemd[1]: Stopping OpenSAF daemon...
2026-06-16 01:49:28.014 SC-1 opensafd: Stopping OpenSAF Services
2026-06-16 01:49:28.016 SC-1 osafamfnd[287]: NO Shutdown initiated
2026-06-16 01:49:28.016 SC-1 osafamfnd[287]: NO Removing assignments from AMF components
2026-06-16 01:49:28.016 SC-1 amf_demo[520]: CSI Remove for 'safCsi=AmfDemo,safSi=AmfDemo,safApp=AmfDemo1'
2026-06-16 01:49:28.016 SC-1 osafamfnd[287]: NO Removed 'safSi=AmfDemo,safApp=AmfDemo1' from 'safSu=SU1,safSg=AmfDemo,safApp=AmfDemo1'
2026-06-16 01:49:28.016 SC-1 osafamfnd[287]: NO Removed assignments from AMF components
2026-06-16 01:49:28.016 SC-1 osafamfnd[287]: NO Terminating all AMF components
...

Only have 'Removed' SI. It should add a 'Removing' record as a pair, used for troubleshooting.

Discussion

  • Thang Duc Nguyen

    Attached patch for reference.

     
  • Nguyen Tran Trung Hau

    • assigned_to: Nguyen Tran Trung Hau
     
  • Nguyen Tran Trung Hau

    • status: unassigned --> assigned
     
  • Thang Duc Nguyen

    Fix duplicate message when trying to lock the SU. Message looked like

    2026-06-23 07:20:38.093 SC-1 osafamfnd[287]: NO Removing 'safSi=AmfDemo,safApp=AmfDemo1' from 'safSu=SU1,safSg=AmfDemo,safApp=AmfDemo1'
    2026-06-23 07:20:38.094 SC-1 osafamfnd[287]: NO Removing 'safSi=AmfDemo,safApp=AmfDemo1' from 'safSu=SU1,safSg=AmfDemo,safApp=AmfDemo1'
    2026-06-23 07:20:38.094 SC-1 amf_demo[479]: CSI Remove for all CSIs
    2026-06-23 07:20:38.094 SC-1 osafamfnd[287]: NO Removed 'safSi=AmfDemo,safApp=AmfDemo1' from 'safSu=SU1,safSg=AmfDemo,safApp=AmfDemo1'
    
     
  • Nguyen Tran Trung Hau

    • status: assigned --> review
     
  • Nguyen Tran Trung Hau

    I updated the fix patch resolving the duplicate issue.
    Below: logging output after fixing the 2 unexpected logging:

    Jun 24 07:57:05 SC-1 amf_demo[893]: Health check 62
    Jun 24 07:57:10 SC-1 osafamfnd[315]: NO Shutdown initiated
    Jun 24 07:57:10 SC-1 osafamfnd[315]: NO Removing assignments from AMF components
    Jun 24 07:57:10 SC-1 osafamfnd[315]: NO Removing 'safSi=AmfDemo,safApp=AmfDemo1' from 'safSu=SU1,safSg=AmfDemo,safApp=AmfDemo1'
    Jun 24 07:57:10 SC-1 amf_demo[893]: CSI Remove for 'safCsi=AmfDemo,safSi=AmfDemo,safApp=AmfDemo1'
    Jun 24 07:57:10 SC-1 osafamfnd[315]: NO Removed 'safSi=AmfDemo,safApp=AmfDemo1' from 'safSu=SU1,safSg=AmfDemo,safApp=AmfDemo1'
    Jun 24 07:57:10 SC-1 osafamfnd[315]: NO Removed assignments from AMF components
    Jun 24 07:57:10 SC-1 osafamfnd[315]: NO Terminating all AMF components
    
    Jun 24 08:07:54 SC-1 amf_demo[1874]: Health check 11
    Jun 24 08:08:02 SC-1 osafamfnd[1684]: NO Removing 'safSi=AmfDemo,safApp=AmfDemo1' from 'safSu=SU1,safSg=AmfDemo,safApp=AmfDemo1'
    Jun 24 08:08:02 SC-1 amf_demo[1874]: CSI Remove for all CSIs
    Jun 24 08:08:02 SC-1 osafamfnd[1684]: NO Removed 'safSi=AmfDemo,safApp=AmfDemo1' from 'safSu=SU1,safSg=AmfDemo,safApp=AmfDemo1'
    Jun 24 08:08:04 SC-1 amf_demo[1874]: Health check 12
    

    But I need to dig into more NPI removal workflows, there could be above logging situations not yet covered

     
  • Nguyen Tran Trung Hau

    After running many tests, I found that NPI with 1 SI logs nothing even with the current fix patch applied.
    Unfortunately, None of the resources support NPI with multiple SI.

    2026-06-24 10:56:39.945 SC-1 systemd[1]: Starting Record System Boot/Shutdown in UTMP...
    2026-06-24 10:56:39.945 SC-1 systemd[1]: Finished Record System Boot/Shutdown in UTMP.
    2026-06-24 10:57:19.668 SC-1 systemd[474]: Reached target Shutdown.
    2026-06-24 10:57:21.414 SC-1 osafamfnd[287]: NO Shutdown initiated
    2026-06-24 10:57:21.607 SC-1 osafamfnd[287]: NO Shutdown completed, exiting
    2026-06-24 10:57:29.482 SC-1 systemd[1]: Starting Record System Boot/Shutdown in UTMP...
    2026-06-24 10:57:29.482 SC-1 systemd[1]: Finished Record System Boot/Shutdown in UTMP.
    
    
    2026-06-24 10:58:09.670 SC-1 systemd[474]: Reached target Shutdown.
    2026-06-24 10:58:11.677 SC-1 osafamfnd[287]: NO Shutdown initiated
    2026-06-24 10:58:11.874 SC-1 osafamfnd[287]: NO Shutdown completed, exiting
    2026-06-24 10:59:05.096 SC-1 systemd[1]: Starting Record System Boot/Shutdown in UTMP...
    2026-06-24 10:59:05.096 SC-1 systemd[1]: Finished Record System Boot/Shutdown in UTMP.
    2026-06-24 10:59:46.167 SC-1 systemd[493]: Reached target Shutdown.
    2026-06-24 10:59:51.486 SC-1 osafamfnd[315]: NO Shutdown initiated
    2026-06-24 10:59:51.686 SC-1 osafamfnd[315]: NO Shutdown completed, exiting
    
     
  • Thang Duc Nguyen

    In V1 version, keep the below code due to it is not modified.

    • if ((su->si_list.n_nodes > 1) && (si == nullptr))
    • LOG_NO("Removing 'all (%u) SIs' from '%s'", su->si_list.n_nodes,
    • su->name.c_str());
     
  • Thang Duc Nguyen

    • status: review --> fixed
     
  • Thang Duc Nguyen

    commit 55de4942aa5786801ef0b3c1ed078cdb5fb1dbd0 (HEAD -> develop, origin/develop, ticket-3400)
    Author: Nguyen Tran Trung Hau Hau.Nguyen@endava.com
    Date: Mon Jun 22 10:31:09 2026 +0000

    amf: inconsistent logging when removing SI during opensaf stopping: [#3400]
    
    When OpenSAF stops, AMFND can log that an SI was removed from
    an SU without logging the matching removal start. This makes
    shutdown troubleshooting harder because the SI removal has only
    a completion record.
    
    Log the concrete SI/SU pair when avnd_su_si_remove() is called
    for a single SI. Keep the existing aggregate all-SI log unchanged.
    
     

Log in to post a comment.

Auth0 Logo