ffdc: Enhance telnet timing to handle large data amount

- Set 1: Enhance telnet
- Set 2: Add logging
- Set 3: Add CLI option log_level, default lowest level INFO

Tests:
- Regression tested

Signed-off-by: Peter D  Phan <peterp@us.ibm.com>
Change-Id: Iedbef2f26cda4377f731a5367600b0c29f73e7ac
Signed-off-by: George Keishing <gkeishin@in.ibm.com>
diff --git a/ffdc/collect_ffdc.py b/ffdc/collect_ffdc.py
index a4f2739..e753857 100644
--- a/ffdc/collect_ffdc.py
+++ b/ffdc/collect_ffdc.py
@@ -38,7 +38,10 @@
               show_default=True,
               help="Select protocol (SSH, SCP, REDFISH) to communicate with remote host. \
                     Default: all available.")
-def cli_ffdc(remote, username, password, ffdc_config, location, remote_type, remote_protocol):
+@click.option('--log_level', default="INFO",
+              show_default=True,
+              help="python logging level (CRITICAL, ERROR, WARNING, INFO, DEBUG)")
+def cli_ffdc(remote, username, password, ffdc_config, location, remote_type, remote_protocol, log_level):
     r"""
     Stand alone CLI to generate and collect FFDC from the selected target.
     """
@@ -47,7 +50,8 @@
 
     if input_options_ok(remote, username, password, ffdc_config, remote_type):
         thisFFDC = FFDCCollector(remote, username, password,
-                                 ffdc_config, location, remote_type, remote_protocol)
+                                 ffdc_config, location,
+                                 remote_type, remote_protocol, log_level)
         thisFFDC.collect_ffdc()
 
         if len(os.listdir(thisFFDC.ffdc_dir_path)) == 0:
diff --git a/ffdc/ffdc_collector.py b/ffdc/ffdc_collector.py
index f31abe6..a50b494 100644
--- a/ffdc/ffdc_collector.py
+++ b/ffdc/ffdc_collector.py
@@ -8,6 +8,7 @@
 import sys
 import yaml
 import time
+import logging
 import platform
 from errno import EACCES, EPERM
 import subprocess
@@ -30,7 +31,8 @@
                  ffdc_config,
                  location,
                  remote_type,
-                 remote_protocol):
+                 remote_protocol,
+                 log_level):
         r"""
         Description of argument(s):
 
@@ -42,31 +44,47 @@
         remote_type             os type of the remote host
 
         """
+
+        self.hostname = hostname
+        self.username = username
+        self.password = password
+        self.ffdc_config = ffdc_config
+        self.location = location + "/" + remote_type.upper()
+        self.ssh_remoteclient = None
+        self.telnet_remoteclient = None
+        self.ffdc_dir_path = ""
+        self.ffdc_prefix = ""
+        self.target_type = remote_type.upper()
+        self.remote_protocol = remote_protocol.upper()
+        self.start_time = 0
+        self.elapsed_time = ''
+        self.logger = None
+
+        # Set prefix values for scp files and directory.
+        # Since the time stamp is at second granularity, these values are set here
+        # to be sure that all files for this run will have same timestamps
+        # and they will be saved in the same directory.
+        # self.location == local system for now
+        self.set_ffdc_defaults()
+
+        # Logger for this run.  Need to be after set_ffdc_defaults()
+        self.script_logging(getattr(logging, log_level.upper()))
+
+        # Verify top level directory exists for storage
+        self.validate_local_store(self.location)
+
         if self.verify_script_env():
-            self.hostname = hostname
-            self.username = username
-            self.password = password
-            self.ffdc_config = ffdc_config
-            self.location = location + "/" + remote_type.upper()
-            self.ssh_remoteclient = None
-            self.telnet_remoteclient = None
-            self.ffdc_dir_path = ""
-            self.ffdc_prefix = ""
-            self.target_type = remote_type.upper()
-            self.remote_protocol = remote_protocol.upper()
-            self.start_time = 0
-            self.elapsed_time = ''
+            # Load default or user define YAML configuration file.
+            with open(self.ffdc_config, 'r') as file:
+                self.ffdc_actions = yaml.load(file, Loader=yaml.FullLoader)
+
+            if self.target_type not in self.ffdc_actions.keys():
+                self.logger.error(
+                    "\n\tERROR: %s is not listed in %s.\n\n" % (self.target_type, self.ffdc_config))
+                sys.exit(-1)
         else:
             sys.exit(-1)
 
-        # Load default or user define YAML configuration file.
-        with open(self.ffdc_config, 'r') as file:
-            self.ffdc_actions = yaml.load(file, Loader=yaml.FullLoader)
-
-        if self.target_type not in self.ffdc_actions.keys():
-            print("\n\tERROR: %s is not listed in %s.\n\n" % (self.target_type, self.ffdc_config))
-            sys.exit(-1)
-
     def verify_script_env(self):
 
         # Import to log version
@@ -78,24 +96,41 @@
         redfishtool_version = self.run_redfishtool('-V').split(' ')[2].strip('\n')
         ipmitool_version = self.run_ipmitool('-V').split(' ')[2]
 
-        print("\n\t---- Script host environment ----")
-        print("\t{:<10}  {:<10}".format('Script hostname', os.uname()[1]))
-        print("\t{:<10}  {:<10}".format('Script host os', platform.platform()))
-        print("\t{:<10}  {:>10}".format('Python', platform.python_version()))
-        print("\t{:<10}  {:>10}".format('PyYAML', yaml.__version__))
-        print("\t{:<10}  {:>10}".format('click', click.__version__))
-        print("\t{:<10}  {:>10}".format('paramiko', paramiko.__version__))
-        print("\t{:<10}  {:>9}".format('redfishtool', redfishtool_version))
-        print("\t{:<10}  {:>12}".format('ipmitool', ipmitool_version))
+        self.logger.info("\n\t---- Script host environment ----")
+        self.logger.info("\t{:<10}  {:<10}".format('Script hostname', os.uname()[1]))
+        self.logger.info("\t{:<10}  {:<10}".format('Script host os', platform.platform()))
+        self.logger.info("\t{:<10}  {:>10}".format('Python', platform.python_version()))
+        self.logger.info("\t{:<10}  {:>10}".format('PyYAML', yaml.__version__))
+        self.logger.info("\t{:<10}  {:>10}".format('click', click.__version__))
+        self.logger.info("\t{:<10}  {:>10}".format('paramiko', paramiko.__version__))
+        self.logger.info("\t{:<10}  {:>9}".format('redfishtool', redfishtool_version))
+        self.logger.info("\t{:<10}  {:>12}".format('ipmitool', ipmitool_version))
 
         if eval(yaml.__version__.replace('.', ',')) < (5, 4, 1):
-            print("\n\tERROR: Python or python packages do not meet minimum version requirement.")
-            print("\tERROR: PyYAML version 5.4.1 or higher is needed.\n")
+            self.logger.error("\n\tERROR: Python or python packages do not meet minimum version requirement.")
+            self.logger.error("\tERROR: PyYAML version 5.4.1 or higher is needed.\n")
             run_env_ok = False
 
-        print("\t---- End script host environment ----")
+        self.logger.info("\t---- End script host environment ----")
         return run_env_ok
 
+    def script_logging(self,
+                       log_level_attr):
+        r"""
+        Create logger
+
+        """
+        self.logger = logging.getLogger()
+        self.logger.setLevel(log_level_attr)
+        log_file_handler = logging.FileHandler(self.ffdc_dir_path + "collector.log")
+
+        stdout_handler = logging.StreamHandler(sys.stdout)
+        self.logger.addHandler(log_file_handler)
+        self.logger.addHandler(stdout_handler)
+
+        # Turn off paramiko INFO logging
+        logging.getLogger("paramiko").setLevel(logging.WARNING)
+
     def target_is_pingable(self):
         r"""
         Check if target system is ping-able.
@@ -103,10 +138,11 @@
         """
         response = os.system("ping -c 1 %s  2>&1 >/dev/null" % self.hostname)
         if response == 0:
-            print("\n\t[Check] %s is ping-able.\t\t [OK]" % self.hostname)
+            self.logger.info("\n\t[Check] %s is ping-able.\t\t [OK]" % self.hostname)
             return True
         else:
-            print("\n>>>>>\tERROR: %s is not ping-able. FFDC collection aborted.\n" % self.hostname)
+            self.logger.error(
+                "\n>>>>>\tERROR: %s is not ping-able. FFDC collection aborted.\n" % self.hostname)
             sys.exit(-1)
 
     def collect_ffdc(self):
@@ -115,7 +151,7 @@
 
         """
 
-        print("\n\t---- Start communicating with %s ----" % self.hostname)
+        self.logger.info("\n\t---- Start communicating with %s ----" % self.hostname)
         self.start_time = time.time()
         working_protocol_list = []
         if self.target_is_pingable():
@@ -127,16 +163,16 @@
             # Redfish
             if self.verify_redfish():
                 working_protocol_list.append("REDFISH")
-                print("\n\t[Check] %s Redfish Service.\t\t [OK]" % self.hostname)
+                self.logger.info("\n\t[Check] %s Redfish Service.\t\t [OK]" % self.hostname)
             else:
-                print("\n\t[Check] %s Redfish Service.\t\t [NOT AVAILABLE]" % self.hostname)
+                self.logger.info("\n\t[Check] %s Redfish Service.\t\t [NOT AVAILABLE]" % self.hostname)
 
             # IPMI
             if self.verify_ipmi():
                 working_protocol_list.append("IPMI")
-                print("\n\t[Check] %s IPMI LAN Service.\t\t [OK]" % self.hostname)
+                self.logger.info("\n\t[Check] %s IPMI LAN Service.\t\t [OK]" % self.hostname)
             else:
-                print("\n\t[Check] %s IPMI LAN Service.\t\t [NOT AVAILABLE]" % self.hostname)
+                self.logger.info("\n\t[Check] %s IPMI LAN Service.\t\t [NOT AVAILABLE]" % self.hostname)
 
             # Telnet
             if self.telnet_to_target_system():
@@ -144,11 +180,11 @@
 
             # Verify top level directory exists for storage
             self.validate_local_store(self.location)
-            print("\n\t---- Completed protocol pre-requisite check ----\n")
+            self.logger.info("\n\t---- Completed protocol pre-requisite check ----\n")
 
             if ((self.remote_protocol not in working_protocol_list) and (self.remote_protocol != 'ALL')):
-                print("\n\tWorking protocol list: %s" % working_protocol_list)
-                print(
+                self.logger.info("\n\tWorking protocol list: %s" % working_protocol_list)
+                self.logger.error(
                     '>>>>>\tERROR: Requested protocol %s is not in working protocol list.\n'
                     % self.remote_protocol)
                 sys.exit(-1)
@@ -166,7 +202,7 @@
                                                 self.password)
 
         if self.ssh_remoteclient.ssh_remoteclient_login():
-            print("\n\t[Check] %s SSH connection established.\t [OK]" % self.hostname)
+            self.logger.info("\n\t[Check] %s SSH connection established.\t [OK]" % self.hostname)
 
             # Check scp connection.
             # If scp connection fails,
@@ -174,7 +210,7 @@
             self.ssh_remoteclient.scp_connection()
             return True
         else:
-            print("\n\t[Check] %s SSH connection.\t [NOT AVAILABLE]" % self.hostname)
+            self.logger.info("\n\t[Check] %s SSH connection.\t [NOT AVAILABLE]" % self.hostname)
             return False
 
     def telnet_to_target_system(self):
@@ -185,10 +221,10 @@
                                                       self.username,
                                                       self.password)
         if self.telnet_remoteclient.tn_remoteclient_login():
-            print("\n\t[Check] %s Telnet connection established.\t [OK]" % self.hostname)
+            self.logger.info("\n\t[Check] %s Telnet connection established.\t [OK]" % self.hostname)
             return True
         else:
-            print("\n\t[Check] %s Telnet connection.\t [NOT AVAILABLE]" % self.hostname)
+            self.logger.info("\n\t[Check] %s Telnet connection.\t [NOT AVAILABLE]" % self.hostname)
             return False
 
     def generate_ffdc(self, working_protocol_list):
@@ -199,22 +235,17 @@
         working_protocol_list    list of confirmed working protocols to connect to remote host.
         """
 
-        print("\n\t---- Executing commands on " + self.hostname + " ----")
-        print("\n\tWorking protocol list: %s" % working_protocol_list)
+        self.logger.info("\n\t---- Executing commands on " + self.hostname + " ----")
+        self.logger.info("\n\tWorking protocol list: %s" % working_protocol_list)
 
-        # Set prefix values for scp files and directory.
-        # Since the time stamp is at second granularity, these values are set here
-        # to be sure that all files for this run will have same timestamps
-        # and they will be saved in the same directory.
-        # self.location == local system for now
-        self.set_ffdc_defaults()
         ffdc_actions = self.ffdc_actions
 
         for machine_type in ffdc_actions.keys():
             if self.target_type != machine_type:
                 continue
 
-            print("\tSystem Type: %s" % machine_type)
+            self.logger.info("\n\tFFDC Path: %s " % self.ffdc_dir_path)
+            self.logger.info("\tSystem Type: %s" % machine_type)
             for k, v in ffdc_actions[machine_type].items():
 
                 if self.remote_protocol != ffdc_actions[machine_type][k]['PROTOCOL'][0] \
@@ -227,25 +258,25 @@
                        or 'SCP' in working_protocol_list:
                         self.protocol_ssh(ffdc_actions, machine_type, k)
                     else:
-                        print("\n\tERROR: SSH or SCP is not available for %s." % self.hostname)
+                        self.logger.error("\n\tERROR: SSH or SCP is not available for %s." % self.hostname)
 
                 if ffdc_actions[machine_type][k]['PROTOCOL'][0] == 'TELNET':
                     if 'TELNET' in working_protocol_list:
                         self.protocol_telnet(ffdc_actions, machine_type, k)
                     else:
-                        print("\n\tERROR: TELNET is not available for %s." % self.hostname)
+                        self.logger.error("\n\tERROR: TELNET is not available for %s." % self.hostname)
 
                 if ffdc_actions[machine_type][k]['PROTOCOL'][0] == 'REDFISH':
                     if 'REDFISH' in working_protocol_list:
                         self.protocol_redfish(ffdc_actions, machine_type, k)
                     else:
-                        print("\n\tERROR: REDFISH is not available for %s." % self.hostname)
+                        self.logger.error("\n\tERROR: REDFISH is not available for %s." % self.hostname)
 
                 if ffdc_actions[machine_type][k]['PROTOCOL'][0] == 'IPMI':
                     if 'IPMI' in working_protocol_list:
                         self.protocol_ipmi(ffdc_actions, machine_type, k)
                     else:
-                        print("\n\tERROR: IMPI is not available for %s." % self.hostname)
+                        self.logger.error("\n\tERROR: IMPI is not available for %s." % self.hostname)
 
         # Close network connection after collecting all files
         self.elapsed_time = time.strftime("%H:%M:%S", time.gmtime(time.time() - self.start_time))
@@ -280,7 +311,7 @@
         ffdc_actions        List of actions from ffdc_config.yaml.
         machine_type        OS Type of remote host.
         """
-        print("\n\t[Run] Executing commands on %s using %s" % (self.hostname, 'TELNET'))
+        self.logger.info("\n\t[Run] Executing commands on %s using %s" % (self.hostname, 'TELNET'))
         telnet_files_saved = []
         progress_counter = 0
         list_of_commands = ffdc_actions[machine_type][sub_type]['COMMANDS']
@@ -291,9 +322,10 @@
                 try:
                     targ_file = ffdc_actions[machine_type][sub_type]['FILES'][index]
                 except IndexError:
-                    targ_file = each_cmd
-                    print("\n\t[WARN] Missing filename to store data from telnet %s." % each_cmd)
-                    print("\t[WARN] Data will be stored in %s." % targ_file)
+                    targ_file = command_txt
+                    self.logger.warning(
+                        "\n\t[WARN] Missing filename to store data from telnet %s." % each_cmd)
+                    self.logger.warning("\t[WARN] Data will be stored in %s." % targ_file)
                 targ_file_with_path = (self.ffdc_dir_path
                                        + self.ffdc_prefix
                                        + targ_file)
@@ -304,9 +336,9 @@
                     telnet_files_saved.append(targ_file)
             progress_counter += 1
             self.print_progress(progress_counter)
-        print("\n\t[Run] Commands execution completed.\t\t [OK]")
+        self.logger.info("\n\t[Run] Commands execution completed.\t\t [OK]")
         for file in telnet_files_saved:
-            print("\n\t\tSuccessfully save file " + file + ".")
+            self.logger.info("\n\t\tSuccessfully save file " + file + ".")
 
     def protocol_redfish(self,
                          ffdc_actions,
@@ -321,7 +353,7 @@
         sub_type            Group type of commands.
         """
 
-        print("\n\t[Run] Executing commands to %s using %s" % (self.hostname, 'REDFISH'))
+        self.logger.info("\n\t[Run] Executing commands to %s using %s" % (self.hostname, 'REDFISH'))
         redfish_files_saved = []
         progress_counter = 0
         list_of_URL = ffdc_actions[machine_type][sub_type]['URL']
@@ -335,8 +367,9 @@
                     targ_file = self.get_file_list(ffdc_actions[machine_type][sub_type])[index]
                 except IndexError:
                     targ_file = each_url.split('/')[-1]
-                    print("\n\t[WARN] Missing filename to store data from redfish URL %s." % each_url)
-                    print("\t[WARN] Data will be stored in %s." % targ_file)
+                    self.logger.warning(
+                        "\n\t[WARN] Missing filename to store data from redfish URL %s." % each_url)
+                    self.logger.warning("\t[WARN] Data will be stored in %s." % targ_file)
 
                 targ_file_with_path = (self.ffdc_dir_path
                                        + self.ffdc_prefix
@@ -351,10 +384,10 @@
             progress_counter += 1
             self.print_progress(progress_counter)
 
-        print("\n\t[Run] Commands execution completed.\t\t [OK]")
+        self.logger.info("\n\t[Run] Commands execution completed.\t\t [OK]")
 
         for file in redfish_files_saved:
-            print("\n\t\tSuccessfully save file " + file + ".")
+            self.logger.info("\n\t\tSuccessfully save file " + file + ".")
 
     def protocol_ipmi(self,
                       ffdc_actions,
@@ -369,7 +402,7 @@
         sub_type            Group type of commands.
         """
 
-        print("\n\t[Run] Executing commands to %s using %s" % (self.hostname, 'IPMI'))
+        self.logger.info("\n\t[Run] Executing commands to %s using %s" % (self.hostname, 'IPMI'))
         ipmi_files_saved = []
         progress_counter = 0
         list_of_cmd = self.get_command_list(ffdc_actions[machine_type][sub_type])
@@ -383,8 +416,8 @@
                     targ_file = self.get_file_list(ffdc_actions[machine_type][sub_type])[index]
                 except IndexError:
                     targ_file = each_cmd.split('/')[-1]
-                    print("\n\t[WARN] Missing filename to store data from IPMI %s." % each_cmd)
-                    print("\t[WARN] Data will be stored in %s." % targ_file)
+                    self.logger.warning("\n\t[WARN] Missing filename to store data from IPMI %s." % each_cmd)
+                    self.logger.warning("\t[WARN] Data will be stored in %s." % targ_file)
 
                 targ_file_with_path = (self.ffdc_dir_path
                                        + self.ffdc_prefix
@@ -399,10 +432,10 @@
             progress_counter += 1
             self.print_progress(progress_counter)
 
-        print("\n\t[Run] Commands execution completed.\t\t [OK]")
+        self.logger.info("\n\t[Run] Commands execution completed.\t\t [OK]")
 
         for file in ipmi_files_saved:
-            print("\n\t\tSuccessfully save file " + file + ".")
+            self.logger.info("\n\t\tSuccessfully save file " + file + ".")
 
     def collect_and_copy_ffdc(self,
                               ffdc_actions_for_machine_type,
@@ -421,13 +454,13 @@
 
         # Copying files
         if self.ssh_remoteclient.scpclient:
-            print("\n\n\tCopying FFDC files from remote system %s.\n" % self.hostname)
+            self.logger.info("\n\n\tCopying FFDC files from remote system %s.\n" % self.hostname)
 
             # Retrieving files from target system
             list_of_files = self.get_file_list(ffdc_actions_for_machine_type)
             self.scp_ffdc(self.ffdc_dir_path, self.ffdc_prefix, form_filename, list_of_files)
         else:
-            print("\n\n\tSkip copying FFDC files from remote system %s.\n" % self.hostname)
+            self.logger.info("\n\n\tSkip copying FFDC files from remote system %s.\n" % self.hostname)
 
     def get_command_list(self,
                          ffdc_actions_for_machine_type):
@@ -485,8 +518,8 @@
         ffdc_actions_for_machine_type    commands and files for the selected remote host type.
         form_filename                    if true, pre-pend self.target_type to filename
         """
-        print("\n\t[Run] Executing commands on %s using %s"
-              % (self.hostname, ffdc_actions_for_machine_type['PROTOCOL'][0]))
+        self.logger.info("\n\t[Run] Executing commands on %s using %s"
+                         % (self.hostname, ffdc_actions_for_machine_type['PROTOCOL'][0]))
 
         list_of_commands = self.get_command_list(ffdc_actions_for_machine_type)
         # If command list is empty, returns
@@ -505,7 +538,7 @@
             progress_counter += 1
             self.print_progress(progress_counter)
 
-        print("\n\t[Run] Commands execution completed.\t\t [OK]")
+        self.logger.info("\n\t[Run] Commands execution completed.\t\t [OK]")
 
     def group_copy(self,
                    ffdc_actions_for_machine_type):
@@ -517,7 +550,7 @@
         """
 
         if self.ssh_remoteclient.scpclient:
-            print("\n\tCopying DUMP files from remote system %s.\n" % self.hostname)
+            self.logger.info("\n\tCopying DUMP files from remote system %s.\n" % self.hostname)
 
             list_of_commands = self.get_command_list(ffdc_actions_for_machine_type)
             # If command list is empty, returns
@@ -528,7 +561,7 @@
                 try:
                     filename = command.split(' ')[2]
                 except IndexError:
-                    print("\t\tInvalid command %s for DUMP_LOGS block." % command)
+                    self.logger.info("\t\tInvalid command %s for DUMP_LOGS block." % command)
                     continue
 
                 err, response = self.ssh_remoteclient.execute_command(command)
@@ -536,12 +569,12 @@
                 if response:
                     scp_result = self.ssh_remoteclient.scp_file_from_remote(filename, self.ffdc_dir_path)
                     if scp_result:
-                        print("\t\tSuccessfully copied from " + self.hostname + ':' + filename)
+                        self.logger.info("\t\tSuccessfully copied from " + self.hostname + ':' + filename)
                 else:
-                    print("\t\tThere is no " + filename)
+                    self.logger.info("\t\tThere is no " + filename)
 
         else:
-            print("\n\n\tSkip copying files from remote system %s.\n" % self.hostname)
+            self.logger.info("\n\n\tSkip copying files from remote system %s.\n" % self.hostname)
 
     def scp_ffdc(self,
                  targ_dir_path,
@@ -575,9 +608,11 @@
 
             if not quiet:
                 if scp_result:
-                    print("\t\tSuccessfully copied from " + self.hostname + ':' + source_file_path + ".\n")
+                    self.logger.info(
+                        "\t\tSuccessfully copied from " + self.hostname + ':' + source_file_path + ".\n")
                 else:
-                    print("\t\tFail to copy from " + self.hostname + ':' + source_file_path + ".\n")
+                    self.logger.info(
+                        "\t\tFail to copy from " + self.hostname + ':' + source_file_path + ".\n")
             else:
                 progress_counter += 1
                 self.print_progress(progress_counter)
@@ -597,7 +632,6 @@
 
         timestr = time.strftime("%Y%m%d-%H%M%S")
         self.ffdc_dir_path = self.location + "/" + self.hostname + "_" + timestr + "/"
-        print("\n\tFFDC Path: %s " % self.ffdc_dir_path)
         self.ffdc_prefix = timestr + "_"
         self.validate_local_store(self.ffdc_dir_path)
 
@@ -616,9 +650,11 @@
             except (IOError, OSError) as e:
                 # PermissionError
                 if e.errno == EPERM or e.errno == EACCES:
-                    print('>>>>>\tERROR: os.makedirs %s failed with PermissionError.\n' % dir_path)
+                    self.logger.error(
+                        '>>>>>\tERROR: os.makedirs %s failed with PermissionError.\n' % dir_path)
                 else:
-                    print('>>>>>\tERROR: os.makedirs %s failed with %s.\n' % (dir_path, e.strerror))
+                    self.logger.error(
+                        '>>>>>\tERROR: os.makedirs %s failed with %s.\n' % (dir_path, e.strerror))
                 sys.exit(-1)
 
     def print_progress(self, progress):
@@ -670,8 +706,8 @@
                                 universal_newlines=True)
 
         if result.stderr and not quiet:
-            print('\n\t\tERROR with redfishtool ' + parms_string)
-            print('\t\t' + result.stderr)
+            self.logger.error('\n\t\tERROR with redfishtool ' + parms_string)
+            self.logger.error('\t\t' + result.stderr)
 
         return result.stdout
 
@@ -693,7 +729,7 @@
                                 universal_newlines=True)
 
         if result.stderr and not quiet:
-            print('\n\t\tERROR with ipmitool -I lanplus -C 17 ' + parms_string)
-            print('\t\t' + result.stderr)
+            self.logger.error('\n\t\tERROR with ipmitool -I lanplus -C 17 ' + parms_string)
+            self.logger.error('\t\t' + result.stderr)
 
         return result.stdout
diff --git a/ffdc/ffdc_config.yaml b/ffdc/ffdc_config.yaml
index ea26aca..45697d8 100644
--- a/ffdc/ffdc_config.yaml
+++ b/ffdc/ffdc_config.yaml
@@ -81,7 +81,7 @@
             - 'SSH'
 
     # DUMP_LOGS: This section provides option to 'SCP if file exist'.
-    #     COMMANDS: filename is preceeded by ls -AX '.
+    #     COMMANDS: filename is preceded by ls -AX '.
     #     FILES: is not needed and is ignored if exists.
     DUMP_LOGS:
         COMMANDS:
diff --git a/ffdc/ssh_utility.py b/ffdc/ssh_utility.py
index 9715948..a8c1253 100644
--- a/ffdc/ssh_utility.py
+++ b/ffdc/ssh_utility.py
@@ -9,6 +9,7 @@
 from scp import SCPClient, SCPException
 import time
 import socket
+import logging
 from socket import timeout as SocketTimeout
 
 
@@ -97,9 +98,9 @@
         except (paramiko.AuthenticationException, paramiko.SSHException,
                 paramiko.ChannelException, SocketTimeout) as e:
             # Log command with error. Return to caller for next command, if any.
-            print("\n>>>>>\tERROR: Fail remote command %s %s" % (e.__class__, e))
-            print(">>>>>\tCommand '%s' Elapsed Time %s" %
-                  (command, time.strftime("%H:%M:%S", time.gmtime(time.time() - cmd_start))))
+            logging.error("\n>>>>>\tERROR: Fail remote command %s %s" % (e.__class__, e))
+            logging.error(">>>>>\tCommand '%s' Elapsed Time %s" %
+                          (command, time.strftime("%H:%M:%S", time.gmtime(time.time() - cmd_start))))
             return empty, empty
 
     def scp_connection(self):
@@ -109,12 +110,12 @@
         """
         try:
             self.scpclient = SCPClient(self.sshclient.get_transport(), sanitize=lambda x: x)
-            print("\n\t[Check] %s SCP transport established.\t [OK]" % self.hostname)
+            logging.info("\n\t[Check] %s SCP transport established.\t [OK]" % self.hostname)
         except (SCPException, SocketTimeout, PipeTimeout) as e:
             self.scpclient = None
-            print("\n>>>>>\tERROR: SCP get_transport has failed. %s %s" % (e.__class__, e))
-            print(">>>>>\tScript continues generating FFDC on %s." % self.hostname)
-            print(">>>>>\tCollected data will need to be manually offloaded.")
+            logging.error("\n>>>>>\tERROR: SCP get_transport has failed. %s %s" % (e.__class__, e))
+            logging.info(">>>>>\tScript continues generating FFDC on %s." % self.hostname)
+            logging.info(">>>>>\tCollected data will need to be manually offloaded.")
 
     def scp_file_from_remote(self, remote_file, local_file):
 
@@ -133,7 +134,8 @@
             self.scpclient.get(remote_file, local_file, recursive=True)
         except (SCPException, SocketTimeout, PipeTimeout) as e:
             # Log command with error. Return to caller for next file, if any.
-            print("\n>>>>>\tERROR: Fail scp %s from remotehost %s %s\n\n" % (remote_file, e.__class__, e))
+            logging.error(
+                "\n>>>>>\tERROR: Fail scp %s from remotehost %s %s\n\n" % (remote_file, e.__class__, e))
             return False
 
         # Return True for file accounting
diff --git a/ffdc/telnet_utility.py b/ffdc/telnet_utility.py
index 8635bf0..761ac58 100644
--- a/ffdc/telnet_utility.py
+++ b/ffdc/telnet_utility.py
@@ -3,6 +3,7 @@
 
 import time
 import socket
+import logging
 import telnetlib
 from collections import deque
 
@@ -47,14 +48,15 @@
                             [b'Login incorrect', b'invalid login name or password.', br'\#', br'\$'],
                             timeout=self.read_timeout)
                     if n == 0 or n == 1:
-                        print("\n>>>>>\tERROR: Telnet Authentication Failed.  Check userid and password.\n\n")
+                        logging.error(
+                            "\n>>>>>\tERROR: Telnet Authentication Failed.  Check userid and password.\n\n")
                         is_telnet = False
                     else:
                         # login successful
                         self.fifo = deque()
                 else:
                     # Anything else, telnet server is not running
-                    print("\n>>>>>\tERROR: Telnet Connection Refused.\n\n")
+                    logging.error("\n>>>>>\tERROR: Telnet Connection Refused.\n\n")
                     is_telnet = False
             else:
                 is_telnet = False
@@ -91,20 +93,25 @@
         '''
 
         # Execute the command and read the command output
-        # Execute the command and read the command output
         return_buffer = b''
         try:
 
-            # Flush whatever data is in the read buffer by doing
-            # a non-blocking read
-            self.tnclient.read_very_eager().decode('utf-8')
+            # Do at least one non-blocking read
+            #  to flush whatever data is in the read buffer.
+            while self.tnclient.read_very_eager():
+                continue
 
             # Execute the command
             self.tnclient.write(cmd.encode('utf-8') + b'\n')
             time.sleep(i_timeout)
 
-            # Read the command output.
+            local_buffer = b''
+            # Read the command output one block at a time.
             return_buffer = self.tnclient.read_very_eager()
+            while return_buffer:
+                local_buffer = b''.join([local_buffer, return_buffer])
+                time.sleep(3)  # let the buffer fill up a bit
+                return_buffer = self.tnclient.read_very_eager()
 
         except (socket.error, EOFError) as e:
             self.tn_remoteclient_disconnect()
@@ -116,6 +123,7 @@
             else:
                 msg = "Some other issue.%s %s %s\n\n" % (cmd, e.__class__, e)
 
-            print("\t\t ERROR %s " % msg)
+            logging.error("\t\t ERROR %s " % msg)
 
-        return return_buffer
+        # Return binary data.
+        return local_buffer