2.7.3 bugfix (#51)

* fix: Add debug mode for troubleshooting

* fix: use correct delimiter when splitting services list

asadm.py

@@ -17,6 +17,7 @@
 import inspect
 import cmd
 import getpass
+import logging
 
 import os
 import re
@@ -62,7 +63,7 @@
 # codec is registered well before it is used in getaddrinfo.
 # see https://bugs.python.org/issue29288, https://github.com/aws/aws-cli/blob/1.16.277/awscli/clidriver.py#L55,
 # and https://github.com/pyinstaller/pyinstaller/issues/1113 for more info :)
-u"".encode("idna")
+"".encode("idna")
 
 __version__ = "$$__version__$$"
 CMD_FILE_SINGLE_LINE_COMMENT_START = "//"
@@ -208,7 +209,7 @@ async def __init__(
 
         except Exception as e:
             await self.do_exit("")
-            logger.critical(str(e))
+            logger.critical(e)
 
         if not execute_only_mode:
 
@@ -627,6 +628,9 @@ async def main():
 
     admin_version = get_version()
 
+    if cli_args.debug:
+        logger.setLevel(logging.DEBUG)
+
     if cli_args.help:
         conf.print_config_help()
         sys.exit(0)

lib/live_cluster/client/assocket.py

@@ -12,6 +12,7 @@
 # See the License for the specific language governing permissions and
 # limitations under the License.
 
+import logging
 import socket
 import warnings
 import asyncio
@@ -53,6 +54,8 @@
 
 
 class ASSocket:
+    logger = logging.getLogger("asadm")
+
     def __init__(
         self, ip, port, tls_name, user, password, auth_mode, ssl_context, timeout=5
     ):
@@ -171,7 +174,8 @@ async def connect(self):
             if not self.sock:
                 return False
             self.reader, self.writer = await asyncio.open_connection(sock=self.sock)
-        except Exception:
+        except Exception as e:
+            self.logger.debug(e, include_traceback=True)
             return False
         return True
 
@@ -185,7 +189,8 @@ async def is_connected(self):
             if result is None or result == -1:
                 return False
 
-        except Exception:
+        except Exception as e:
+            self.logger.debug(e, include_traceback=True)
             return False
 
         return True

lib/live_cluster/client/cluster.py

@@ -24,12 +24,11 @@
 from lib.utils.async_object import AsyncObject
 
 from lib.utils.lookup_dict import LookupDict
-from lib.utils import logger_debug, util, constants
+from lib.utils import util, constants
 
 from . import client_util
 from .node import Node
 
-logger = logger_debug.get_debug_logger(__name__, logging.CRITICAL)
 
 # interval time in second for cluster refreshing
 CLUSTER_REFRESH_INTERVAL = 3
@@ -233,8 +232,8 @@ async def get_down_nodes(self):
                         _key = Node.create_key(n[0], n[1])
                         if _key not in cluster_down_nodes:
                             cluster_down_nodes.append(_key)
-            except Exception:
-                pass
+            except Exception as e:
+                self.logger.debug(e, include_traceback=True)
 
         return cluster_down_nodes
 
@@ -256,8 +255,8 @@ def update_aliases(self, aliases, endpoints, key):
                         node = self.nodes[aliases_node_key]
                         if not node.alive:
                             aliases[node_key] = key
-            except Exception:
-                pass
+            except Exception as e:
+                self.logger.debug(e, include_traceback=True)
 
     async def find_new_nodes(self):
         added_endpoints = []
@@ -299,7 +298,7 @@ async def _crawl(self):
         """
         nodes_to_add = await self.find_new_nodes()
 
-        logger.debug("Nodes to add to cluster: %s", nodes_to_add)
+        self.logger.debug("Unvisited nodes: %s", nodes_to_add)
 
         if not nodes_to_add or len(nodes_to_add) == 0:
             return
@@ -310,7 +309,9 @@ async def _crawl(self):
 
             while unvisited - visited:
                 l_unvisited = list(unvisited)
-                logger.debug("Register nodes in cluster: %s", l_unvisited)
+                self.logger.debug(
+                    "Attempting to add nodes to the cluster: %s", l_unvisited
+                )
                 nodes = await client_util.concurrent_map(
                     self._register_node, l_unvisited
                 )
@@ -348,11 +349,12 @@ async def _crawl(self):
                         all_services.add((node.ip, node.port, node.tls_name))
 
                 unvisited = all_services - visited
-                logger.debug("Peers to add to cluster: %s", unvisited)
+                self.logger.debug("Peers to add to cluster: %s", unvisited)
 
             self._refresh_node_liveliness()
-        except Exception:
-            pass
+        except Exception as e:
+            self.logger.debug(e, include_traceback=True)
+
         finally:
             self.clear_node_list()
 
@@ -538,8 +540,8 @@ async def _create_node(self, addr_port_tls, force=False):
             return new_node
         except (ASInfoNotAuthenticatedError, ASProtocolError) as e:
             self.logger.error(e)
-        except Exception:
-            pass
+        except Exception as e:
+            self.logger.debug(e, include_traceback=True)
         return None
 
     @staticmethod

lib/live_cluster/client/info.py

@@ -42,8 +42,7 @@
     # fatal when authentication is required.
     hasbcrypt = False
 
-logger = logging.getLogger(__name__)
-logger.setLevel(logging.CRITICAL)
+logger = logging.getLogger("asadm")
 
 
 # There are three different headers referenced here in the code. I am adding
@@ -1320,6 +1319,13 @@ async def info(reader, writer, names=None):
         if name != names:
             if "not authenticated" in name.lower():
                 return ASInfoNotAuthenticatedError("Connection failed", name)
+            else:
+                logger.debug(
+                    "Unexpected key %s in info response %s. Expected key: %s",
+                    name,
+                    lines,
+                    names,
+                )
         return value
 
     else:
@@ -1331,6 +1337,15 @@ async def info(reader, writer, names=None):
                 # this accounts for the trailing '\n' - cheaper than chomp
                 continue
             name, sep, value = line.partition("\t")
+
+            if name not in names:
+                logger.debug(
+                    "Unexpected key %s in info response %s. Exceptable keys: %s",
+                    name,
+                    line,
+                    names,
+                )
+
             rdict[name] = value
         return rdict
 

lib/live_cluster/client/node.py

@@ -346,7 +346,7 @@ async def connect(self, address, port):
         except (ASInfoNotAuthenticatedError, ASProtocolError):
             raise
         except Exception as e:
-
+            self.logger.debug(e, include_traceback=True)
             # Node is offline... fake a node
             self.ip = address
             self.fqdn = address
@@ -399,14 +399,14 @@ async def login(self):
 
         try:
             if not await sock.login():
-                logger.debug(
+                self.logger.debug(
                     "%s:%s failed to login to socket %s", self.ip, self.port, sock
                 )
                 await sock.close()
                 return False
         except ASProtocolError as e:
             if e.as_response == ASResponse.SECURITY_NOT_ENABLED:
-                logger.debug(
+                self.logger.debug(
                     "%s:%s failed to login to socket, security not enabled, ignoring... %s",
                     self.ip,
                     self.port,
@@ -416,7 +416,7 @@ async def login(self):
                     self.logger.warning(e)
                     Node.security_disabled_warning = True
             else:
-                logger.debug(
+                self.logger.debug(
                     "%s:%s failed to login to socket %s, exc: %s",
                     self.ip,
                     self.port,
@@ -429,7 +429,9 @@ async def login(self):
         self.socket_pool[self.port].add(sock)
         self.session_token, self.session_expiration = sock.get_session_info()
         self.perform_login = False
-        logger.debug("%s:%s successful login to socket %s", self.ip, self.port, sock)
+        self.logger.debug(
+            "%s:%s successful login to socket %s", self.ip, self.port, sock
+        )
         return True
 
     @property
@@ -528,7 +530,8 @@ async def _get_connection(self, ip, port) -> ASSocket:
                 await sock.close()
                 sock = None
 
-        except Exception:
+        except Exception as e:
+            self.logger.debug(e, include_traceback=True)
             pass
 
         if sock:
@@ -545,15 +548,15 @@ async def _get_connection(self, ip, port) -> ASSocket:
             timeout=self._timeout,
         )
 
-        logger.debug("%s:%s created new sock %s", ip, port, id(sock))
+        self.logger.debug("%s:%s created new sock %s", ip, port, id(sock))
 
         if await sock.connect():
             try:
                 if await sock.authenticate(self.session_token):
-                    logger.debug("sock auth successful %s", id(sock))
+                    self.logger.debug("sock auth successful %s", id(sock))
                     return sock
             except ASProtocolError as e:
-                logger.debug("sock auth failed %s", id(sock))
+                self.logger.debug("sock auth failed %s", id(sock))
                 if e.as_response == ASResponse.SECURITY_NOT_ENABLED:
                     # A user/pass was provided and security is disabled. This is OK
                     # and a warning should have been displayed at login
@@ -564,17 +567,19 @@ async def _get_connection(self, ip, port) -> ASSocket:
                 ):
                     # A node likely switched from security disabled to security enable.
                     # In which case the error is caused by login never being called.
-                    logger.debug("trying to sock login again %s", id(sock))
+                    self.logger.debug("trying to sock login again %s", id(sock))
                     self.perform_login = True
                     await self.login()
                     if await sock.authenticate(self.session_token):
-                        logger.debug("sock auth successful on second try %s", id(sock))
+                        self.logger.debug(
+                            "sock auth successful on second try %s", id(sock)
+                        )
                         return sock
 
                 await sock.close()
                 raise
 
-        logger.debug("sock connect failed %s", id(sock))
+        self.logger.debug("sock connect failed %s", id(sock))
         return None
 
     async def close(self):
@@ -632,7 +637,7 @@ async def _info_cinfo(self, command, ip=None, port=None):
                     await sock.close()
 
             if result != -1 and result is not None:
-                logger.debug(
+                self.logger.debug(
                     "%s:%s info cmd '%s' and sock %s returned %s",
                     self.ip,
                     self.port,
@@ -649,7 +654,7 @@ async def _info_cinfo(self, command, ip=None, port=None):
             if sock:
                 await sock.close()
 
-            logger.debug(
+            self.logger.debug(
                 "%s:%s info cmd '%s' and sock %s raised %s for",
                 self.ip,
                 self.port,
@@ -845,7 +850,7 @@ async def info_peers_flat_list(self):
     # post 3.10 services
 
     # @return_exceptions
-    def _info_service_helper(self, service, delimiter=";"):
+    def _info_service_helper(self, service, delimiter=","):
         if not service or isinstance(service, Exception):
             return []
         s = [
@@ -881,9 +886,7 @@ async def info_service_list(self):
         Returns:
         list -- [(ip,port,tls_name),...]
         """
-        return self._info_service_helper(
-            await self.info(self._get_service_info_call()), ","
-        )
+        return self._info_service_helper(await self.info(self._get_service_info_call()))
 
     ###### Service End ######
 

lib/utils/conf.py

@@ -665,6 +665,7 @@ def get_cli_args():
     add_fn("-f", "--log-path")
     add_fn("-j", "--json", action="store_true")
     add_fn("--no-color", action="store_true")
+    add_fn("--debug", action="store_true")
     add_fn("--profile", action="store_true")
     add_fn("--single-node", action="store_true")
     add_fn("--line-separator", action="store_true")