[Multi-asic] On LC init one ASIC ends up in TSA while the other ends up in TSB

[arista-nwolfe]

There is a race condition introduced by #21587 where each swss instance is going to restart the startup_tsa_tsb.service when they come up.
This results in the startup_tsa_tsb.service stopping 2 times and starting 3 times.

E.G.

2025 Feb 20 19:28:39.844540 cmp227-4 NOTICE kernel: [    0.000000] Linux version 6.1.0-22-2-amd64

1. Started by Systemd

2025 Feb 20 19:28:51.626593 cmp227-4 INFO systemd[1]: Started startup_tsa_tsb.service - STARTUP TSA-TSB SERVICE.
2025 Feb 20 19:28:52.631791 cmp227-4 INFO startup_tsa_tsb: asic0 - CONFIG_DB.BGP_DEVICE_GLOBAL.STATE.tsa_enabled : false
2025 Feb 20 19:28:53.290011 cmp227-4 INFO startup_tsa_tsb: asic1 - CONFIG_DB.BGP_DEVICE_GLOBAL.STATE.tsa_enabled : false
2025 Feb 20 19:28:53.290118 cmp227-4 INFO startup_tsa_tsb: Configuring TSA

2. Restarted by swss0 (stopped and started)

2025 Feb 20 19:28:53.929423 cmp227-4 INFO swss.sh[3355]: swss0: starting TSA-TSB service
2025 Feb 20 19:28:53.939779 cmp227-4 INFO systemd[1]: Stopping startup_tsa_tsb.service - STARTUP TSA-TSB SERVICE...
2025 Feb 20 19:28:54.070178 cmp227-4 INFO startup_tsa_tsb: Resetting environment variable
2025 Feb 20 19:28:54.094711 cmp227-4 INFO systemd[1]: startup_tsa_tsb.service: Deactivated successfully.
2025 Feb 20 19:28:54.094981 cmp227-4 INFO systemd[1]: Stopped startup_tsa_tsb.service - STARTUP TSA-TSB SERVICE.
2025 Feb 20 19:28:54.375061 cmp227-4 INFO systemd[1]: Started startup_tsa_tsb.service - STARTUP TSA-TSB SERVICE.
2025 Feb 20 19:28:55.215203 cmp227-4 INFO startup_tsa_tsb: asic0 - CONFIG_DB.BGP_DEVICE_GLOBAL.STATE.tsa_enabled : false
2025 Feb 20 19:28:55.788054 cmp227-4 INFO startup_tsa_tsb: asic1 - CONFIG_DB.BGP_DEVICE_GLOBAL.STATE.tsa_enabled : false
2025 Feb 20 19:28:55.788102 cmp227-4 INFO startup_tsa_tsb: Configuring TSA
2025 Feb 20 19:28:58.479678 cmp227-4 INFO TSA: System Mode: Normal -> Maintenance

3. Restarted by swss1 (stopped and started)

2025 Feb 20 19:28:58.888987 cmp227-4 INFO swss.sh[4588]: swss1: starting TSA-TSB service
2025 Feb 20 19:28:58.926216 cmp227-4 INFO systemd[1]: Stopping startup_tsa_tsb.service - STARTUP TSA-TSB SERVICE...
2025 Feb 20 19:28:59.087019 cmp227-4 INFO startup_tsa_tsb: Resetting environment variable
2025 Feb 20 19:28:59.124181 cmp227-4 INFO systemd[1]: startup_tsa_tsb.service: Deactivated successfully.
2025 Feb 20 19:28:59.124519 cmp227-4 INFO systemd[1]: Stopped startup_tsa_tsb.service - STARTUP TSA-TSB SERVICE.
2025 Feb 20 19:28:59.162638 cmp227-4 INFO systemd[1]: Started startup_tsa_tsb.service - STARTUP TSA-TSB SERVICE.
2025 Feb 20 19:29:00.030231 cmp227-4 INFO startup_tsa_tsb: asic0 - CONFIG_DB.BGP_DEVICE_GLOBAL.STATE.tsa_enabled : true
2025 Feb 20 19:29:00.726294 cmp227-4 INFO startup_tsa_tsb: asic1 - CONFIG_DB.BGP_DEVICE_GLOBAL.STATE.tsa_enabled : false
2025 Feb 20 19:29:00.736585 cmp227-4 INFO startup_tsa_tsb: Either TSA is already configured or switch sub_role is not Frontend - not configuring TSA

The problem with this stopping and starting is we could kill the process at any point and could cause the state between asic instances to be out of sync.

See the last restart logs:

2025 Feb 20 19:29:00.030231 cmp227-4 INFO startup_tsa_tsb: asic0 - CONFIG_DB.BGP_DEVICE_GLOBAL.STATE.tsa_enabled : true
2025 Feb 20 19:29:00.726294 cmp227-4 INFO startup_tsa_tsb: asic1 - CONFIG_DB.BGP_DEVICE_GLOBAL.STATE.tsa_enabled : false

tsa_enabled is True for asic0 but False for asic1`.

This is because TSA iterates over the asics one at a time and writes tsa_enabled=true, so if swss1 kills this service when it's written to asic0 but not asic1 we end up in this state.

The bigger issue here is that tsa_enabled=true is set on either asic's config_db but the following entry doesn't exist in STATE_DB:
'sonic-db-cli', 'STATE_DB', 'HSET', 'ALL_SERVICE_STATUS|tsa_tsb_service', 'running', 'OK'

This is because this write occurs after the TSA is complete:

69     if tsa_ena == True:
70         logger.log_info("Configuring TSA")
71         subprocess.check_output(['TSA']).strip()
72         logger.log_info("Setting TSA-TSB service field in STATE_DB")
73         subprocess.check_output([
74             'sonic-db-cli', 'STATE_DB', 'HSET', 'ALL_SERVICE_STATUS|tsa_tsb_service', 'running', 'OK'
75         ]).strip()

And note we don't see Setting TSA-TSB service field in STATE_DB in any of the logs above.

Without the ALL_SERVICE_STATUS|tsa_tsb_service we won't return True in config_tsa:

77         #check if tsa_tsb service is already running, restart the timer
78         try:
79             startup_tsa_tsb_service_status = subprocess.check_output([
80                 'sonic-db-cli', 'STATE_DB', 'HGET', 'ALL_SERVICE_STATUS|tsa_tsb_service', 'running'
81             ]).strip().decode('utf-8')  # Convert bytes to string
82         except subprocess.CalledProcessError:
83             startup_tsa_tsb_service_status = None  # Default if the field is missing
84
85         if startup_tsa_tsb_service_status == 'OK':
86             logger.log_info("TSA-TSB service is already running, just restart the timer")
87             return True
88         else:
89             if num_asics > 1:
90                 logger.log_info("Either TSA is already configured or switch sub_role is not Frontend - not configuring TSA")
91             else:
92                 logger.log_info("Either TSA is already configured - not configuring TSA")

Which is why we see the log on line 90 instead.

With config_tsa returning False we won't start the timer and therefor won't take asic0 out of TSA

130 def start_tsa_tsb(timer):
131     #Configure TSA if it was not configured already in CONFIG_DB
132     tsa_enabled = config_tsa()
133     if tsa_enabled == True:
134         #Start the timer to configure TSB
135         start_tsb_timer(timer)
136     return

root@cmp227-4# TSC
BGP0 : System Mode: Maintenance
BGP1 : System Mode: Normal
The rates are calculated within 5 seconds period