Jac/logging

tabcmd/commands/auth/login_command.py

@@ -22,4 +22,4 @@ def run_command(args):
         logger = log(__class__.__name__, args.logging_level)
         logger.debug(_("tabcmd.launching"))
         session = Session()
-        session.create_session(args)
+        session.create_session(args, logger)

tabcmd/commands/auth/session.py

@@ -48,8 +48,8 @@ def __init__(self):
         self.timeout = None
 
         self.logging_level = "info"
-        self._read_from_json()
         self.logger = log(__name__, self.logging_level)  # instantiate here mostly for tests
+        self._read_from_json()
         self.tableau_server = None  # this one is an object that doesn't get persisted in the file
 
     # called before we connect to the server
@@ -206,7 +206,7 @@ def _create_new_connection(self) -> TSC.Server:
         return self.tableau_server
 
     def _read_existing_state(self):
-        if self._check_json():
+        if self._json_exists():
             self._read_from_json()
 
     def _print_server_info(self):
@@ -265,13 +265,13 @@ def _get_saved_credentials(self):
         return credentials
 
     # external entry point:
-    def create_session(self, args):
+    def create_session(self, args, logger):
         signed_in_object = None
         # pull out cached info from json, then overwrite with new args if available
         self._read_existing_state()
         self._update_session_data(args)
         self.logging_level = args.logging_level or self.logging_level
-        self.logger = self.logger or log(__class__.__name__, self.logging_level)
+        self.logger = logger or log(__class__.__name__, self.logging_level)
 
         credentials = None
         if args.password:
@@ -344,51 +344,70 @@ def _clear_data(self):
         self.timeout = None
 
     # json file functions ----------------------------------------------------
+    # These should be moved into a separate class
     def _get_file_path(self):
         home_path = os.path.expanduser("~")
         file_path = os.path.join(home_path, "tableau_auth.json")
         return file_path
 
     def _read_from_json(self):
-        if not self._check_json():
+        if not self._json_exists():
             return
         file_path = self._get_file_path()
-        data = {}
-        with open(str(file_path), "r") as file_contents:
-            data = json.load(file_contents)
+        content = None
         try:
-            for auth in data["tableau_auth"]:
-                self.auth_token = auth["auth_token"]
-                self.server_url = auth["server"]
-                self.site_name = auth["site_name"]
-                self.site_id = auth["site_id"]
-                self.username = auth["username"]
-                self.user_id = auth["user_id"]
-                self.token_name = auth["personal_access_token_name"]
-                self.token_value = auth["personal_access_token"]
-                self.last_login_using = auth["last_login_using"]
-                self.password_file = auth["password_file"]
-                self.no_prompt = auth["no_prompt"]
-                self.no_certcheck = auth["no_certcheck"]
-                self.certificate = auth["certificate"]
-                self.no_proxy = auth["no_proxy"]
-                self.proxy = auth["proxy"]
-                self.timeout = auth["timeout"]
-        except KeyError as e:
-            self.logger.debug(_("sessionoptions.errors.bad_password_file"), e)
-            self._remove_json()
-        except Exception as any_error:
-            self.logger.info(_("session.new_session"))
-            self._remove_json()
+            with open(str(file_path), "r") as file_contents:
+                data = json.load(file_contents)
+                content = data["tableau_auth"]
+        except json.JSONDecodeError as e:
+            self._wipe_bad_json(e, "Error reading data from session file")
+        except IOError as e:
+            self._wipe_bad_json(e, "Error reading session file")
+        except AttributeError as e:
+            self._wipe_bad_json(e, "Error parsing session details from file")
+        except Exception as e:
+            self._wipe_bad_json(e, "Unexpected error reading session details from file")
+
+        try:
+            auth = content[0]
+            self.auth_token = auth["auth_token"]
+            self.server_url = auth["server"]
+            self.site_name = auth["site_name"]
+            self.site_id = auth["site_id"]
+            self.username = auth["username"]
+            self.user_id = auth["user_id"]
+            self.token_name = auth["personal_access_token_name"]
+            self.token_value = auth["personal_access_token"]
+            self.last_login_using = auth["last_login_using"]
+            self.password_file = auth["password_file"]
+            self.no_prompt = auth["no_prompt"]
+            self.no_certcheck = auth["no_certcheck"]
+            self.certificate = auth["certificate"]
+            self.no_proxy = auth["no_proxy"]
+            self.proxy = auth["proxy"]
+            self.timeout = auth["timeout"]
+        except AttributeError as e:
+            self._wipe_bad_json(e, "Unrecognized attribute in session file")
+        except Exception as e:
+            self._wipe_bad_json(e, "Failed to load session file")
 
-    def _check_json(self):
+    def _wipe_bad_json(self, e, message):
+        self.logger.debug(message + ": " + e.__str__())
+        self.logger.info(_("session.new_session"))
+        self._remove_json()
+
+    def _json_exists(self):
+        # todo: make this location configurable
         home_path = os.path.expanduser("~")
         file_path = os.path.join(home_path, "tableau_auth.json")
         return os.path.exists(file_path)
 
     def _save_session_to_json(self):
-        data = self._serialize_for_save()
-        self._save_file(data)
+        try:
+            data = self._serialize_for_save()
+            self._save_file(data)
+        except Exception as e:
+            self._wipe_bad_json(e, "Failed to save session file")
 
     def _save_file(self, data):
         file_path = self._get_file_path()
@@ -420,7 +439,15 @@ def _serialize_for_save(self):
         return data
 
     def _remove_json(self):
-        file_path = self._get_file_path()
-        self._save_file({})
-        if os.path.exists(file_path):
-            os.remove(file_path)
+        file_path = ""
+        try:
+            if not self._json_exists():
+                return
+            file_path = self._get_file_path()
+            self._save_file({})
+            if os.path.exists(file_path):
+                os.remove(file_path)
+        except Exception as e:
+            message = "Error clearing session data from {}: check and remove manually".format(file_path)
+            self.logger.error(message)
+            self.logger.error(e)

tabcmd/commands/constants.py

@@ -1,8 +1,6 @@
 import inspect
 import sys
 
-from tableauserverclient import ServerResponseError
-
 from tabcmd.execution.localize import _
 
 
@@ -25,20 +23,19 @@ def is_expired_session(error):
     @staticmethod
     def is_resource_conflict(error):
         if hasattr(error, "code"):
-            return error.code == Constants.source_already_exists
+            return error.code.startswith(Constants.resource_conflict_general)
 
     @staticmethod
     def is_login_error(error):
         if hasattr(error, "code"):
             return error.code == Constants.login_error
 
-    @staticmethod
-    def is_server_response_error(error):
-        return isinstance(error, ServerResponseError)
-
     # https://gist.github.com/FredLoney/5454553
     @staticmethod
     def log_stack(logger):
+        if not logger:
+            print("logger not available: cannot show stack")
+            return
         try:
             """The log header message formatter."""
             HEADER_FMT = "Printing Call Stack at %s::%s"
@@ -49,11 +46,10 @@ def log_stack(logger):
             file, line, func = here[1:4]
             start = 0
             n_lines = 5
-            logger.trace(HEADER_FMT % (file, func))
-
-            for frame in stack[start + 2 : n_lines]:
+            logger.debug(HEADER_FMT % (file, func))
+            for frame in stack[start + 1 : n_lines]:
                 file, line, func = frame[1:4]
-                logger.trace(STACK_FMT % (file, line, func))
+                logger.debug(STACK_FMT % (file, line, func))
         except Exception as e:
             logger.info("Error printing stack trace:", e)
 
@@ -66,9 +62,9 @@ def exit_with_error(logger, message=None, exception=None):
             if exception:
                 if message:
                     logger.debug("Error message: " + message)
-                Errors.check_common_error_codes_and_explain(logger, exception)
+            Errors.check_common_error_codes_and_explain(logger, exception)
         except Exception as exc:
-            print(sys.stderr, "Error during log call from exception - {}".format(exc))
+            print(sys.stderr, "Error during log call from exception - {} {}".format(exc.__class__, message))
         try:
             logger.info("Exiting...")
         except Exception:
@@ -77,16 +73,15 @@ def exit_with_error(logger, message=None, exception=None):
 
     @staticmethod
     def check_common_error_codes_and_explain(logger, exception):
-        if Errors.is_server_response_error(exception):
-            logger.error(_("publish.errors.unexpected_server_response").format(exception))
-            if Errors.is_expired_session(exception):
-                logger.error(_("session.errors.session_expired"))
-                # TODO: add session as an argument to this method
-                #  and add the full command line as a field in Session?
-                # "session.session_expired_login"))
-                # session.renew_session
-                return
-            if exception.code == Constants.source_not_found:
-                logger.error(_("publish.errors.server_resource_not_found"), exception)
+        # most errors contain as much info in the message as we can get from the code
+        # identify any that we can add useful detail for and include them here
+        if Errors.is_expired_session(exception):
+            # catch this one so we can attempt to refresh the session before telling them it failed
+            logger.error(_("session.errors.session_expired"))
+            # TODO: add session as an argument to this method
+            #  and add the full command line as a field in Session?
+            # "session.session_expired_login"))
+            # session.renew_session()
+            return
         else:
             logger.error(exception)

tabcmd/commands/datasources_and_workbooks/delete_command.py

@@ -32,7 +32,7 @@ def run_command(args):
         logger = log(__class__.__name__, args.logging_level)
         logger.debug(_("tabcmd.launching"))
         session = Session()
-        server = session.create_session(args)
+        server = session.create_session(args, logger)
         content_type: str = ""
         if args.workbook:
             content_type = "workbook"

tabcmd/commands/datasources_and_workbooks/export_command.py

@@ -73,7 +73,7 @@ def run_command(args):
         logger = log(__class__.__name__, args.logging_level)
         logger.debug(_("tabcmd.launching"))
         session = Session()
-        server = session.create_session(args)
+        server = session.create_session(args, logger)
         view_content_url, wb_content_url = ExportCommand.parse_export_url_to_workbook_and_view(logger, args.url)
         logger.debug([view_content_url, wb_content_url])
         if not view_content_url and not wb_content_url:

tabcmd/commands/datasources_and_workbooks/get_url_command.py

@@ -41,7 +41,7 @@ def run_command(args):
         logger = log(__class__.__name__, args.logging_level)
         logger.debug(_("tabcmd.launching"))
         session = Session()
-        server = session.create_session(args)
+        server = session.create_session(args, logger)
         if " " in args.url:
             Errors.exit_with_error(logger, _("export.errors.white_space_workbook_view"))
 

tabcmd/commands/datasources_and_workbooks/publish_command.py

@@ -36,7 +36,7 @@ def run_command(args):
         logger = log(__class__.__name__, args.logging_level)
         logger.debug(_("tabcmd.launching"))
         session = Session()
-        server = session.create_session(args)
+        server = session.create_session(args, logger)
 
         if args.project_name:
             try:

tabcmd/commands/datasources_and_workbooks/runschedule_command.py

@@ -23,7 +23,7 @@ def run_command(args):
         logger = log(__class__.__name__, args.logging_level)
         logger.debug(_("tabcmd.launching"))
         session = Session()
-        server = session.create_session(args)
+        server = session.create_session(args, logger)
         schedule = DatasourcesAndWorkbooks.get_items_by_name(logger, server.schedules, args.schedule)[0]
         logger.info(_("runschedule.status"))
         Errors.exit_with_error(logger, "Not yet implemented")

tabcmd/commands/extracts/create_extracts_command.py

@@ -31,7 +31,7 @@ def run_command(args):
         logger = log(__class__.__name__, args.logging_level)
         logger.debug(_("tabcmd.launching"))
         session = Session()
-        server = session.create_session(args)
+        server = session.create_session(args, logger)
         creation_call = None
         try:
             logger.debug(

tabcmd/commands/extracts/decrypt_extracts_command.py

@@ -24,7 +24,7 @@ def run_command(args):
         logger = log(__class__.__name__, args.logging_level)
         logger.debug(_("tabcmd.launching"))
         session = Session()
-        server = session.create_session(args)
+        server = session.create_session(args, logger)
         site_item = Server.get_site_for_command_or_throw(logger, server, args.site_name)
         try:
             logger.info(_("decryptextracts.status").format(args.site_name))

tabcmd/commands/extracts/delete_extracts_command.py

@@ -31,7 +31,7 @@ def run_command(args):
         logger = log(__class__.__name__, args.logging_level)
         logger.debug(_("tabcmd.launching"))
         session = Session()
-        server = session.create_session(args)
+        server = session.create_session(args, logger)
         try:
             if args.datasource:
                 logger.info(_("deleteextracts.for.datasource").format(args.datasource))

tabcmd/commands/extracts/encrypt_extracts_command.py

@@ -26,7 +26,7 @@ def run_command(args):
         logger = log(__class__.__name__, args.logging_level)
         logger.debug(_("tabcmd.launching"))
         session = Session()
-        server = session.create_session(args)
+        server = session.create_session(args, logger)
         site_item = Server.get_site_for_command_or_throw(logger, server, args.site_name)
         try:
             logger.info(_("encryptextracts.status").format(site_item.name))

tabcmd/commands/extracts/reencrypt_extracts_command.py

@@ -26,7 +26,7 @@ def run_command(args):
         logger = log(__class__.__name__, args.logging_level)
         logger.debug(_("tabcmd.launching"))
         session = Session()
-        server = session.create_session(args)
+        server = session.create_session(args, logger)
         site_item = Server.get_site_for_command_or_throw(logger, server, args.site_name)
         try:
             logger.info(_("reencryptextracts.status").format(site_item.name))

tabcmd/commands/extracts/refresh_extracts_command.py

@@ -33,7 +33,7 @@ def run_command(args):
         logger = log(__class__.__name__, args.logging_level)
         logger.debug(_("tabcmd.launching"))
         session = Session()
-        server = session.create_session(args)
+        server = session.create_session(args, logger)
         refresh_action = "refresh"
 
         if args.addcalculations or args.removecalculations:

tabcmd/commands/group/create_group_command.py

@@ -25,7 +25,7 @@ def run_command(args):
         logger = log(__class__.__name__, args.logging_level)
         logger.debug(_("tabcmd.launching"))
         session = Session()
-        server = session.create_session(args)
+        server = session.create_session(args, logger)
         try:
             logger.info(_("creategroup.status").format(args.name))
             new_group = TSC.GroupItem(args.name)

tabcmd/commands/group/delete_group_command.py

@@ -25,7 +25,7 @@ def run_command(args):
         logger = log(__class__.__name__, args.logging_level)
         logger.debug(_("tabcmd.launching"))
         session = Session()
-        server = session.create_session(args)
+        server = session.create_session(args, logger)
         try:
             logger.info(_("tabcmd.find.group").format(args.name))
             group_id = Server.find_group(logger, server, args.name).id

tabcmd/commands/project/create_project_command.py

@@ -30,7 +30,7 @@ def run_command(args):
         logger = log(__class__.__name__, args.logging_level)
         logger.debug(_("tabcmd.launching"))
         session = Session()
-        server = session.create_session(args)
+        server = session.create_session(args, logger)
         parent_id = None
         readable_name = args.project_name
         if args.parent_project_path:

tabcmd/commands/project/delete_project_command.py

@@ -27,7 +27,7 @@ def run_command(args):
         logger = log(__class__.__name__, args.logging_level)
         logger.debug(_("tabcmd.launching"))
         session = Session()
-        server = session.create_session(args)
+        server = session.create_session(args, logger)
         if args.parent_project_path:
             logger.debug("parent path: {}".format(args.parent_project_path))
 

tabcmd/commands/project/publish_samples_command.py

@@ -31,7 +31,7 @@ def run_command(args):
         logger = log(__class__.__name__, args.logging_level)
         logger.debug(_("tabcmd.launching"))
         session = Session()
-        server = session.create_session(args)
+        server = session.create_session(args, logger)
         try:
             project = PublishSamplesCommand.get_project_by_name_and_parent_path(
                 logger, server, args.project_name, args.parent_project_path