From 82fd968011b481f11cfec6a1ec767e095d3f41db Mon Sep 17 00:00:00 2001
From: Slawek Kaplonski <skaplons@redhat.com>
Date: Thu, 12 Aug 2021 16:48:57 +0200
Subject: [PATCH] [L3HA] Add extra logs to the process of ha state changes

Some extra debug logs may be useful to understand exactly what happens
during ha states transitions and e.g. to understand failures like
described in the related bug.

Related-bug: #1939507
Change-Id: Id708b2c7a602df8d4ba1b32e58d4b152b5c58ba6
---
 neutron/agent/l3/ha.py        |  8 +++++++-
 neutron/agent/l3/ha_router.py | 13 ++++++++-----
 2 files changed, 15 insertions(+), 6 deletions(-)

diff --git a/neutron/agent/l3/ha.py b/neutron/agent/l3/ha.py
index 7f9e466bc02..dfb56c5787a 100644
--- a/neutron/agent/l3/ha.py
+++ b/neutron/agent/l3/ha.py
@@ -141,6 +141,8 @@ class AgentMixin(object):
         :param state: ['primary', 'backup']
         """
         if not self._update_transition_state(router_id, state):
+            LOG.debug("Enqueueing router's %s state change to %s",
+                      router_id, state)
             eventlet.spawn_n(self._enqueue_state_change, router_id, state)
             eventlet.sleep(0)
 
@@ -148,10 +150,14 @@ class AgentMixin(object):
         # NOTE(ralonsoh): move 'primary' and 'backup' constants to n-lib
         if state == 'primary':
             eventlet.sleep(self.conf.ha_vrrp_advert_int)
-        if self._update_transition_state(router_id) != state:
+        transition_state = self._update_transition_state(router_id)
+        if transition_state != state:
             # If the current "transition state" is not the initial "state" sent
             # to update the router, that means the actual router state is the
             # same as the "transition state" (e.g.: backup-->primary-->backup).
+            LOG.debug("Current transition state of router %s: %s; "
+                      "Initial state was: %s",
+                      router_id, transition_state, state)
             return
 
         ri = self._get_router_info(router_id)
diff --git a/neutron/agent/l3/ha_router.py b/neutron/agent/l3/ha_router.py
index b91448c7deb..845618bce9b 100644
--- a/neutron/agent/l3/ha_router.py
+++ b/neutron/agent/l3/ha_router.py
@@ -101,6 +101,8 @@ class HaRouter(router.RouterInfo):
         if (not self.keepalived_manager.check_processes() and
                 os.path.exists(self.ha_state_path) and
                 self.ha_state == 'primary'):
+            LOG.debug("Setting ha_state of router %s to: backup",
+                      self.router_id)
             self.ha_state = 'backup'
 
     @property
@@ -115,8 +117,9 @@ class HaRouter(router.RouterInfo):
                 ha_state = f.read()
                 ha_state = 'primary' if ha_state == 'master' else ha_state
                 self._ha_state = ha_state
-        except (OSError, IOError):
-            LOG.debug('Error while reading HA state for %s', self.router_id)
+        except (OSError, IOError) as error:
+            LOG.debug('Error while reading HA state for %s: %s',
+                      self.router_id, error)
         return self._ha_state or 'unknown'
 
     @ha_state.setter
@@ -125,9 +128,9 @@ class HaRouter(router.RouterInfo):
         try:
             with open(self.ha_state_path, 'w') as f:
                 f.write(new_state)
-        except (OSError, IOError):
-            LOG.error('Error while writing HA state for %s',
-                      self.router_id)
+        except (OSError, IOError) as error:
+            LOG.error('Error while writing HA state for %s: %s',
+                      self.router_id, error)
 
     @property
     def ha_namespace(self):