From mboxrd@z Thu Jan 1 00:00:00 1970 From: Marek 'marx' Grac Date: Wed, 2 Apr 2014 17:06:17 +0200 Subject: [Cluster-devel] [PATCH] fencing: Replace printing to stderr with proper logging solution Message-ID: <1396451177-3648-1-git-send-email-mgrac@redhat.com> List-Id: To: cluster-devel.redhat.com MIME-Version: 1.0 Content-Type: text/plain; charset="us-ascii" Content-Transfer-Encoding: 7bit This patch replaces local solutions by standard python logging module. Levels of messages is not final, it just reflects the previous state. So, debug level is available only with -v / verbose option. --- fence/agents/amt/fence_amt.py | 33 +++++++++++++++---------- fence/agents/cisco_ucs/fence_cisco_ucs.py | 6 ++--- fence/agents/dummy/fence_dummy.py | 3 ++- fence/agents/eps/fence_eps.py | 15 ++++-------- fence/agents/ipmilan/fence_ipmilan.py | 26 ++++++++++---------- fence/agents/lib/XenAPI.py.py | 4 ++-- fence/agents/lib/fencing.py.py | 40 +++++++++++++++++-------------- fence/agents/lib/fencing_snmp.py.py | 4 ++-- fence/agents/ovh/fence_ovh.py | 16 ++++++------- fence/agents/rhevm/fence_rhevm.py | 6 ++--- fence/agents/sanbox2/fence_sanbox2.py | 3 ++- fence/agents/vmware/fence_vmware.py | 4 ++-- 12 files changed, 84 insertions(+), 76 deletions(-) diff --git a/fence/agents/amt/fence_amt.py b/fence/agents/amt/fence_amt.py index 81b8aec..f4dff4b 100644 --- a/fence/agents/amt/fence_amt.py +++ b/fence/agents/amt/fence_amt.py @@ -1,6 +1,7 @@ #!/usr/bin/python import sys, subprocess, re, os, stat +import logging from pipes import quote sys.path.append("@FENCEAGENTSLIBDIR@") from fencing import * @@ -15,19 +16,19 @@ def get_power_status(_, options): cmd = create_command(options, "status") - if options["log"] >= LOG_MODE_VERBOSE: - options["debug_fh"].write("executing: " + cmd + "\n") - try: + logging.debug("Running: %s" % cmd) process = subprocess.Popen(cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE, shell=True) except OSError: fail_usage("Amttool not found or not accessible") process.wait() - output = process.communicate() + out = process.communicate() process.stdout.close() - options["debug_fh"].write(output) + process.stderr.close() + logging.debug("%s\n" % str(out)) + match = re.search('Powerstate:[\\s]*(..)', str(output)) status = match.group(1) if match else None @@ -43,30 +44,36 @@ def set_power_status(_, options): cmd = create_command(options, options["--action"]) - if options["log"] >= LOG_MODE_VERBOSE: - options["debug_fh"].write("executing: " + cmd + "\n") - try: - process = subprocess.Popen(cmd, stdout=options["debug_fh"], stderr=options["debug_fh"], shell=True) + logging.debug("Running: %s" % cmd) + process = subprocess.Popen(cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE, shell=True) except OSError: fail_usage("Amttool not found or not accessible") process.wait() + out = process.communicate() + process.stdout.close() + process.stderr.close() + logging.debug("%s\n" % str(out)) + return def reboot_cycle(_, options): cmd = create_command(options, "cycle") - if options["log"] >= LOG_MODE_VERBOSE: - options["debug_fh"].write("executing: " + cmd + "\n") - try: - process = subprocess.Popen(cmd, stdout=options["debug_fh"], stderr=options["debug_fh"], shell=True) + logging.debug("Running: %s" % cmd) + process = subprocess.Popen(cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE, shell=True) except OSError: fail_usage("Amttool not found or not accessible") status = process.wait() + + out = process.communicate() + process.stdout.close() + process.stderr.close() + logging.debug("%s\n" % str(out)) return not bool(status) diff --git a/fence/agents/cisco_ucs/fence_cisco_ucs.py b/fence/agents/cisco_ucs/fence_cisco_ucs.py index 71782cb..dc413d8 100644 --- a/fence/agents/cisco_ucs/fence_cisco_ucs.py +++ b/fence/agents/cisco_ucs/fence_cisco_ucs.py @@ -2,6 +2,7 @@ import sys, re import pycurl, StringIO +import logging sys.path.append("@FENCEAGENTSLIBDIR@") from fencing import * @@ -90,9 +91,8 @@ def send_command(opt, command, timeout): c.perform() result = b.getvalue() - if opt["log"] >= LOG_MODE_VERBOSE: - opt["debug_fh"].write(command + "\n") - opt["debug_fh"].write(result + "\n") + logging.debug("%s\n" % command) + logging.debug("%s\n" % results) return result diff --git a/fence/agents/dummy/fence_dummy.py b/fence/agents/dummy/fence_dummy.py index d5bb748..95a3579 100644 --- a/fence/agents/dummy/fence_dummy.py +++ b/fence/agents/dummy/fence_dummy.py @@ -1,6 +1,7 @@ #!/usr/bin/python import sys, re, pexpect, exceptions, random +import logging sys.path.append("@FENCEAGENTSLIBDIR@") from fencing import * @@ -117,7 +118,7 @@ def main(): if options.has_key("--random_sleep_range"): val = int(options["--random_sleep_range"]) ran = random.randint(1, val) - sys.stderr.write("random sleep for %d seconds\n" % ran) + logging.info("Random sleep for %d seconds\n" % ran) time.sleep(ran) if options["--type"] == "fail": diff --git a/fence/agents/eps/fence_eps.py b/fence/agents/eps/fence_eps.py index 0e7709d..be50bd5 100644 --- a/fence/agents/eps/fence_eps.py +++ b/fence/agents/eps/fence_eps.py @@ -5,6 +5,7 @@ import sys, re import httplib, base64, string, socket +import logging sys.path.append("@FENCEAGENTSLIBDIR@") from fencing import * @@ -14,11 +15,6 @@ REDHAT_COPYRIGHT="" BUILD_DATE="" #END_VERSION_GENERATION -# Log actions and results from EPS device -def eps_log(options, str): - if options["log"] >= LOG_MODE_VERBOSE: - options["debug_fh"].write(str) - # Run command on EPS device. # @param options Device options # @param params HTTP GET parameters (without ?) @@ -32,7 +28,7 @@ def eps_run_command(options, params): if (params!=""): request_str += "?"+params - eps_log(options, "GET "+request_str+"\n") + logging.debug("GET %s\n" % request_str) conn.putrequest('GET', request_str) if (options.has_key("--username")): @@ -41,23 +37,22 @@ def eps_run_command(options, params): # String for Authorization header auth_str = 'Basic ' + string.strip(base64.encodestring(options["--username"]+':'+options["--password"])) - eps_log(options, "Authorization:"+auth_str+"\n") + logging.debug("Authorization: %s\n" % auth_str) conn.putheader('Authorization', auth_str) conn.endheaders() response = conn.getresponse() - eps_log(options, "%d %s\n"%(response.status, response.reason)) + logging.debug("%d %s\n"%(response.status, response.reason)) #Response != OK -> couldn't login if (response.status!=200): fail(EC_LOGIN_DENIED) result = response.read() - eps_log(options, result+"\n") + logging.debug("%s \n" % result) conn.close() - except socket.timeout: fail(EC_TIMED_OUT) except socket.error: diff --git a/fence/agents/ipmilan/fence_ipmilan.py b/fence/agents/ipmilan/fence_ipmilan.py index de42524..4731be1 100644 --- a/fence/agents/ipmilan/fence_ipmilan.py +++ b/fence/agents/ipmilan/fence_ipmilan.py @@ -1,6 +1,7 @@ #!/usr/bin/python import sys, shlex, stat, subprocess, re, os +import logging from pipes import quote sys.path.append("@FENCEAGENTSLIBDIR@") from fencing import * @@ -15,10 +16,8 @@ def get_power_status(_, options): cmd = create_command(options, "status") - if options["log"] >= LOG_MODE_VERBOSE: - options["debug_fh"].write("executing: " + cmd + "\n") - try: + logging.info("Executing: %s\n" % cmd) process = subprocess.Popen(shlex.split(cmd), stdout=subprocess.PIPE, stderr=subprocess.PIPE) except OSError: fail_usage("Ipmitool not found or not accessible") @@ -27,7 +26,8 @@ def get_power_status(_, options): out = process.communicate() process.stdout.close() - options["debug_fh"].write(str(out) + "\n") + process.stderr.close() + logging.debug("%s\n" % str(out)) match = re.search('[Cc]hassis [Pp]ower is [\\s]*([a-zA-Z]{2,3})', str(out)) status = match.group(1) if match else None @@ -38,25 +38,26 @@ def set_power_status(_, options): cmd = create_command(options, options["--action"]) - if options["log"] >= LOG_MODE_VERBOSE: - options["debug_fh"].write("executing: " + cmd + "\n") - try: - process = subprocess.Popen(shlex.split(cmd), stdout=options["debug_fh"], stderr=options["debug_fh"]) + logging.debug("Executing: %s\n" % cmd) + process = subprocess.Popen(shlex.split(cmd), stdout=subprocess.PIPE, stderr=subprocess.PIPE) except OSError: fail_usage("Ipmitool not found or not accessible") process.wait() + out = process.communicate() + process.stdout.close() + process.stderr.close() + logging.debug("%s\n" % str(out)) + return def reboot_cycle(_, options): cmd = create_command(options, "cycle") - if options["log"] >= LOG_MODE_VERBOSE: - options["debug_fh"].write("executing: " + cmd + "\n") - try: + logging.debug("Executing: %s\n" % cmd) process = subprocess.Popen(shlex.split(cmd), stdout=subprocess.PIPE, stderr=subprocess.PIPE) except OSError: fail_usage("Ipmitool not found or not accessible") @@ -65,7 +66,8 @@ def reboot_cycle(_, options): out = process.communicate() process.stdout.close() - options["debug_fh"].write(str(out) + "\n") + process.stderr.close() + logging.debug("%s\n" % str(out)) return bool(re.search('chassis power control: cycle', str(out).lower())) diff --git a/fence/agents/lib/XenAPI.py.py b/fence/agents/lib/XenAPI.py.py index ce905fd..9928bba 100644 --- a/fence/agents/lib/XenAPI.py.py +++ b/fence/agents/lib/XenAPI.py.py @@ -48,6 +48,7 @@ import gettext import xmlrpclib import httplib import socket +import logging translation = gettext.translation('xen-xm', fallback = True) @@ -72,8 +73,7 @@ class Failure(Exception): return "Message database broken: %s.\nXen-API failure: %s" % \ (exn, str(self.details)) except Exception, exn: - import sys - print >> sys.stderr, exn + logging.error("%s\n" % str(exn)) return "Xen-API failure: %s" % str(self.details) def _details_map(self): diff --git a/fence/agents/lib/fencing.py.py b/fence/agents/lib/fencing.py.py index 5dd188e..48c5540 100644 --- a/fence/agents/lib/fencing.py.py +++ b/fence/agents/lib/fencing.py.py @@ -2,6 +2,7 @@ import sys, getopt, time, os, uuid, pycurl, stat import pexpect, re, atexit, syslog +import logging import __main__ ## do not add code here. @@ -376,15 +377,19 @@ DEPENDENCY_OPT = { class fspawn(pexpect.spawn): def __init__(self, options, command): + logging.info("Running command: %s" % command) pexpect.spawn.__init__(self, command) self.opt = options def log_expect(self, options, pattern, timeout): result = self.expect(pattern, timeout) - if options["log"] >= LOG_MODE_VERBOSE: - options["debug_fh"].write(self.before + self.after) + logging.debug("Received: %s" % (self.before + self.after)) return result + def send(self, message): + logging.debug("Sent: %s" % message) + pexpect.spawn.send(self,message) + # send EOL according to what was detected in login process (telnet) def send_eol(self, message): self.send(message + self.opt["eol"]) @@ -394,7 +399,7 @@ def atexit_handler(): sys.stdout.close() os.close(1) except IOError: - sys.stderr.write("%s failed to close standard output\n"%(sys.argv[0])) + logging.error("%s failed to close standard output\n" % (sys.argv[0])) syslog.syslog(syslog.LOG_ERR, "Failed to close standard output") sys.exit(EC_GENERIC_ERROR) @@ -414,8 +419,8 @@ def version(command, release, build_date, copyright_notice): def fail_usage(message = ""): if len(message) > 0: - sys.stderr.write(message+"\n") - sys.stderr.write("Please use '-h' for usage\n") + logging.error("%s\n" % message) + logging.error("Please use '-h' for usage\n") sys.exit(EC_GENERIC_ERROR) def fail(error_code): @@ -431,7 +436,7 @@ def fail(error_code): EC_PASSWORD_MISSING : "Failed: You have to set login password", EC_INVALID_PRIVILEGES : "Failed: The user does not have the correct privileges to do the requested action." }[error_code] + "\n" - sys.stderr.write(message) + logging.error("%s\n" % message) syslog.syslog(syslog.LOG_ERR, message) sys.exit(EC_GENERIC_ERROR) @@ -598,7 +603,7 @@ def process_input(avail_opt): value = value[:-1] if avail_opt.count(name) == 0: - sys.stderr.write("Parse error: Ignoring unknown option '"+line+"'\n") + logging.warning("Parse error: Ignoring unknown option '%s'\n" % line) syslog.syslog(syslog.LOG_WARNING, "Parse error: Ignoring unknown option '"+line) continue @@ -672,9 +677,7 @@ def check_input(device_opt, opt): options["--action"] = options["--action"].lower() if options.has_key("--verbose"): - options["log"] = LOG_MODE_VERBOSE - else: - options["log"] = LOG_MODE_QUIET + logging.getLogger().setLevel(logging.DEBUG) acceptable_actions = [ "on", "off", "status", "list", "monitor" ] if 1 == device_opt.count("fabric_fencing"): @@ -725,13 +728,13 @@ def check_input(device_opt, opt): if options.has_key("--debug-file"): try: - options["debug_fh"] = file (options["--debug-file"], "w") + fh = logging.FileHandler(options["--debug-file"]) + fh.setLevel(logging.DEBUG) + logging.getLogger().addHandler(fh) except IOError: + logging.error("Unable to create file %s" % options["--debug-file"]) fail_usage("Failed: Unable to create file " + options["--debug-file"]) - if options.has_key("debug_fh") == 0: - options["debug_fh"] = sys.stderr - if options.has_key("--snmp-priv-passwd-script"): options["--snmp-priv-passwd"] = os.popen(options["--snmp-priv-passwd-script"]).read().rstrip() @@ -916,13 +919,13 @@ def fence_action(tn, options, set_power_fn, get_power_fn, get_outlet_list = None except Exception, ex: # an error occured during power ON phase in reboot # fence action was completed succesfully even in that case - sys.stderr.write(str(ex)) + logging.error("%s\n", str(ex)) syslog.syslog(syslog.LOG_NOTICE, str(ex)) pass if power_on == False: # this should not fail as node was fenced succesfully - sys.stderr.write('Timed out waiting to power ON\n') + logging.error('Timed out waiting to power ON\n') syslog.syslog(syslog.LOG_NOTICE, "Timed out waiting to power ON") print "Success: Rebooted" @@ -937,7 +940,7 @@ def fence_action(tn, options, set_power_fn, get_power_fn, get_outlet_list = None except pexpect.TIMEOUT: fail(EC_TIMED_OUT) except pycurl.error, ex: - sys.stderr.write(ex[1] + "\n") + logging.error("%s\n" % str(ex)) syslog.syslog(syslog.LOG_ERR, ex[1]) fail(EC_TIMED_OUT) @@ -961,6 +964,7 @@ def fence_login(options, re_login_string = "(login\s*: )|(Login Name: )|(userna ## Do the delay of the fence device before logging in ## Delay is important for two-node clusters fencing but we do not need to delay 'status' operations if options["--action"] in ["off", "reboot"]: + logging.info("Delay %s second(s) before logging in to the fence device" % options["--delay"]) time.sleep(int(options["--delay"])) try: @@ -976,7 +980,7 @@ def fence_login(options, re_login_string = "(login\s*: )|(Login Name: )|(userna try: conn = fspawn(options, command) except pexpect.ExceptionPexpect, ex: - sys.stderr.write(str(ex) + "\n") + logging.error("%s\n" % str(ex)) syslog.syslog(syslog.LOG_ERR, str(ex)) sys.exit(EC_GENERIC_ERROR) elif options.has_key("--ssh") and 0 == options.has_key("--identity-file"): diff --git a/fence/agents/lib/fencing_snmp.py.py b/fence/agents/lib/fencing_snmp.py.py index 0112494..a5d7ef5 100644 --- a/fence/agents/lib/fencing_snmp.py.py +++ b/fence/agents/lib/fencing_snmp.py.py @@ -3,6 +3,7 @@ # For example of use please see fence_cisco_mds import re, pexpect +import logging from fencing import * ## do not add code here. @@ -22,8 +23,7 @@ class FencingSnmp: # Log message if user set verbose option def log_command(self, message): - if self.options["log"] >= LOG_MODE_VERBOSE: - self.options["debug_fh"].write(message+"\n") + logging.debug("%s\n" % message) def quote_for_run(self, string): return ''.join(map(lambda x:x==r"'" and "'\\''" or x, string)) diff --git a/fence/agents/ovh/fence_ovh.py b/fence/agents/ovh/fence_ovh.py index 2ec3fa0..c6c5ded 100644 --- a/fence/agents/ovh/fence_ovh.py +++ b/fence/agents/ovh/fence_ovh.py @@ -10,6 +10,7 @@ import sys, time import shutil, tempfile +import logging from datetime import datetime from suds.client import Client from suds.xsd.doctor import ImportDoctor, Import @@ -122,20 +123,17 @@ Poweroff is simulated with a reboot into rescue-pro mode." # Verify that action was completed sucesfully reboot_t = reboot_time(options) - if options.has_key("--verbose"): - options["debug_fh"].write("reboot_start_end.start: "+ reboot_t.start.strftime('%Y-%m-%d %H:%M:%S')+"\n") - options["debug_fh"].write("before_netboot_reboot: " + before_netboot_reboot.strftime('%Y-%m-%d %H:%M:%S')+"\n") - options["debug_fh"].write("reboot_start_end.end: " + reboot_t.end.strftime('%Y-%m-%d %H:%M:%S')+"\n") - options["debug_fh"].write("after_netboot_reboot: " + after_netboot_reboot.strftime('%Y-%m-%d %H:%M:%S')+"\n") + logging.debug("reboot_start_end.start: %s\n" % reboot_t.start.strftime('%Y-%m-%d %H:%M:%S')) + logging.debug("before_netboot_reboot: %s\n" % before_netboot_reboot.strftime('%Y-%m-%d %H:%M:%S')) + logging.debug("reboot_start_end.end: %s\n" % reboot_t.end.strftime('%Y-%m-%d %H:%M:%S')) + logging.debug("after_netboot_reboot: %s\n" % after_netboot_reboot.strftime('%Y-%m-%d %H:%M:%S')) if reboot_t.start < after_netboot_reboot < reboot_t.end: result = 0 - if options.has_key("--verbose"): - options["debug_fh"].write("Netboot reboot went OK.\n") + logging.debug("Netboot reboot went OK.\n") else: result = 1 - if options.has_key("--verbose"): - options["debug_fh"].write("ERROR: Netboot reboot wasn't OK.\n") + logging.debug("ERROR: Netboot reboot wasn't OK.\n") sys.exit(result) diff --git a/fence/agents/rhevm/fence_rhevm.py b/fence/agents/rhevm/fence_rhevm.py index ff3d19f..96a4cfa 100644 --- a/fence/agents/rhevm/fence_rhevm.py +++ b/fence/agents/rhevm/fence_rhevm.py @@ -2,6 +2,7 @@ import sys, re import pycurl, StringIO +import logging sys.path.append("@FENCEAGENTSLIBDIR@") from fencing import * @@ -94,9 +95,8 @@ def send_command(opt, command, method = "GET"): c.perform() result = b.getvalue() - if opt["log"] >= LOG_MODE_VERBOSE: - opt["debug_fh"].write(command + "\n") - opt["debug_fh"].write(result + "\n") + logging.debug("%s\n" % command) + logging.debug("%s\n" % result) return result diff --git a/fence/agents/sanbox2/fence_sanbox2.py b/fence/agents/sanbox2/fence_sanbox2.py index 5221d49..8f6b702 100644 --- a/fence/agents/sanbox2/fence_sanbox2.py +++ b/fence/agents/sanbox2/fence_sanbox2.py @@ -9,6 +9,7 @@ ##### import sys, re, pexpect, exceptions +import logging sys.path.append("@FENCEAGENTSLIBDIR@") from fencing import * @@ -129,7 +130,7 @@ because the connection will block any necessary fencing actions." if (re.search("\(admin\)", conn.before, re.MULTILINE) == None): ## Someone else is in admin section, we can't enable/disable ## ports so we will rather exit - sys.stderr.write("Failed: Unable to switch to admin section\n") + logging.error("Failed: Unable to switch to admin section\n") sys.exit(EC_GENERIC_ERROR) result = fence_action(conn, options, set_power_status, get_power_status, get_list_devices) diff --git a/fence/agents/vmware/fence_vmware.py b/fence/agents/vmware/fence_vmware.py index dc4ef0f..b27cd95 100644 --- a/fence/agents/vmware/fence_vmware.py +++ b/fence/agents/vmware/fence_vmware.py @@ -23,6 +23,7 @@ # import sys, re, pexpect, exceptions +import logging sys.path.append("@FENCEAGENTSLIBDIR@") from fencing import * @@ -136,8 +137,7 @@ def vmware_prepare_command(options, add_login_params, additional_params): # Log message if user set verbose option def vmware_log(options, message): - if options["log"] >= LOG_MODE_VERBOSE: - options["debug_fh"].write(message+"\n") + logging.debug("%s\n" % message) # Run command with timeout and parameters. Internaly uses vmware_prepare_command. Returns string # with output from vmrun command. If something fails (command not found, exit code is not 0), fail_usage -- 1.9.0