diff --git a/alignak/action.py b/alignak/action.py index e6627ec6b..363f32c50 100644 --- a/alignak/action.py +++ b/alignak/action.py @@ -62,51 +62,42 @@ import sys import subprocess import signal +import psutil -# Try to read in non-blocking mode, from now this only from now on -# Unix systems -try: - import fcntl # pylint: disable=C0103 -except ImportError: - fcntl = None # pylint: disable=C0103 - -from alignak.property import BoolProp, IntegerProp, FloatProp -from alignak.property import StringProp, DictProp from alignak.alignakobject import AlignakObject +from alignak.property import BoolProp, IntegerProp, FloatProp, StringProp, DictProp -logger = logging.getLogger(__name__) # pylint: disable=C0103 -__all__ = ('Action', ) +logger = logging.getLogger(__name__) # pylint: disable=C0103 VALID_EXIT_STATUS = (0, 1, 2, 3) -ONLY_COPY_PROP = ('uuid', 'status', 'command', 't_to_go', 'timeout', - 'env', 'module_type', 'execution_time', 'u_time', 's_time') +ONLY_COPY_PROP = ('uuid', 'status', 'command', 't_to_go', 'timeout', 'env', + 'module_type', 'execution_time', 'u_time', 's_time') SHELLCHARS = ('!', '$', '^', '&', '*', '(', ')', '~', '[', ']', - '|', '{', '}', ';', '<', '>', '?', '`') + '|', '{', '}', ';', '<', '>', '?', '`') -def no_block_read(output): - """Try to read a file descriptor in a non blocking mode +class ActionError(Exception): + """Exception raised for errors when executing actions - :param output: file or socket to read from - :type output: file - :return: data read from fd - :rtype: str + Attributes: + msg -- explanation of the error """ - o_fd = output.fileno() - o_fl = fcntl.fcntl(o_fd, fcntl.F_GETFL) - fcntl.fcntl(o_fd, fcntl.F_SETFL, o_fl | os.O_NONBLOCK) - try: - return output.read() - except Exception: # pylint: disable=broad-except - return '' + + def __init__(self, msg): + super(ActionError, self).__init__() + self.message = msg + + def __str__(self): # pragma: no cover + """Exception to String""" + return "Action error: %s" % self.message -class ActionBase(AlignakObject): +class Action(AlignakObject): """ - This abstract class is used just for having a common id for both + This abstract class is used just for having a common base for both actions and checks. """ process = None @@ -153,7 +144,7 @@ class ActionBase(AlignakObject): } def __init__(self, params=None, parsing=True): - super(ActionBase, self).__init__(params, parsing=parsing) + super(Action, self).__init__(params, parsing=parsing) # Set a creation time only if not provided if not params or 'creation_time' not in params: @@ -189,20 +180,28 @@ def get_local_environnement(self): # instance). local_env = os.environ.copy() for local_var in self.env: - local_env[local_var] = self.env[local_var].encode('utf8') + local_env[local_var] = self.env[local_var] return local_env - def execute(self): - """Start this action command. The command will be executed in a - subprocess. + def execute(self, force_shell=False): + """Start this action command in a subprocess - :return: None or str 'toomanyopenfiles' - :rtype: None | str + :param force_shell: set to force subprocess start with a system shell + :type: bool + + :raise: ActionError + 'toomanyopenfiles' if too many opened files on the system + 'no_process_launched' if arguments parsing failed + 'process_launch_failed': if the process launch failed + + :return: reference to the started process + :rtype: psutil.Process """ self.status = 'launched' self.check_time = time.time() self.wait_time = 0.0001 self.last_poll = self.check_time + # Get a local env variables with our additional values self.local_env = self.get_local_environnement() @@ -212,30 +211,85 @@ def execute(self): self.stderrdata = '' logger.debug("Launch command: '%s', ref: %s", self.command, self.ref) + print("Launch command: '%s', ref: %s" % (self.command, self.ref)) if self.log_actions: if os.environ['ALIGNAK_LOG_ACTIONS'] == 'WARNING': logger.warning("Launch command: '%s'", self.command) else: logger.info("Launch command: '%s'", self.command) - return self.execute__() # OS specific part + # If the command line got shell characters, we should go + # in a shell mode. So look at these parameters + force_shell |= self.got_shell_characters() + logger.debug("Action execute, force shell: %s", force_shell) + print("Action execute, force shell: %s" % force_shell) + + try: + cmd = shlex.split(self.command) + except Exception as exp: # pylint: disable=broad-except + self.output = 'Not a valid shell command: ' + str(exp) + self.exit_status = 3 + self.status = 'done' + self.execution_time = time.time() - self.check_time + raise ActionError('no_process_launched') + + # Now: GO for launch! + logger.debug("Action execute, cmd: %s", cmd) - def get_outputs(self, out, max_plugins_output_length): + # The preexec_fn=os.setsid is set to give sons a same process group. + # See http://www.doughellmann.com/PyMOTW/subprocess/ for some details about this. + try: + self.process = psutil.Popen(cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE, + close_fds=True, shell=force_shell, env=self.local_env, + preexec_fn=os.setsid) + print("Process: %s" % self.process) + logger.debug("Action execute, process: %s", self.process.pid) + except OSError as exp: + logger.error("Fail launching command: %s, force shell: %s, OSError: %s", + self.command, force_shell, exp) + # Maybe it's just a shell we try to exec. So we must retry + if (not force_shell and exp.errno == 8 and + exp.strerror == 'Exec format error'): + logger.info("Retrying with forced shell...") + return self.execute(True) + + self.output = str(exp) + self.exit_status = 2 + self.status = 'done' + self.execution_time = time.time() - self.check_time + + # Maybe we run out of file descriptor. It's not good at all! + if exp.errno == 24 and exp.strerror == 'Too many open files': + raise ActionError('toomanyopenfiles') + + raise ActionError('process_launch_failed') + except Exception as exp: # pylint: disable=broad-except + logger.error("Fail launching command: %s, force shell: %s, exception: %s", + self.command, force_shell, exp) + raise ActionError('process_launch_failed') + + logger.info("- %s launched (pid=%d, gids=%s)", + self.process.name(), self.process.pid, self.process.gids()) + + return self.process + + def get_outputs(self, out, max_output): """Get outputs from single output (split perfdata etc). Edit output, perf_data and long_output attributes. :param out: output data of a check :type out: str - :param max_plugins_output_length: max plugin data length - :type max_plugins_output_length: int + :param max_output: max plugin data length + :type max_output: int :return: None """ - # Squeeze all output after max_plugins_output_length - out = out[:max_plugins_output_length] + # Squeeze all output after max_output + out = out[:max_output] # manage escaped pipes out = out.replace(r'\|', '___PROTECT_PIPE___') # Then cuts by lines elts = out.split('\n') + print("Output: %s" % elts) # For perf data elts_line1 = elts[0].split('|') @@ -245,6 +299,9 @@ def get_outputs(self, out, max_plugins_output_length): self.output = self.output.decode('utf8', 'ignore') except UnicodeEncodeError: pass + except AttributeError: + pass + print("output: %s" % self.output) # Init perfdata as empty self.perf_data = '' @@ -270,8 +327,10 @@ def get_outputs(self, out, max_plugins_output_length): # long_output is all non output and performance data, joined with \n self.long_output = '\n'.join(long_output) + print("long_output: %s" % self.long_output) # Get sure the performance data are stripped self.perf_data = self.perf_data.strip() + print("perf_data: %s" % self.perf_data) logger.debug("Command result for '%s': %d, %s", self.command, self.exit_status, self.output) @@ -302,29 +361,35 @@ def check_finished(self, max_plugins_output_length): _, _, child_utime, child_stime, _ = os.times() + # Not yet finished... if self.process.poll() is None: logger.debug("Process pid=%d is still alive", self.process.pid) # polling every 1/2 s ... for a timeout in seconds, this is enough self.wait_time = min(self.wait_time * 2, 0.5) now = time.time() - # If the fcntl is available (unix) we try to read in a - # asynchronous mode, so we won't block the PIPE at 64K buffer - # (deadlock...) - if fcntl: - self.stdoutdata += no_block_read(self.process.stdout) - self.stderrdata += no_block_read(self.process.stderr) + try: + (self.stdoutdata, self.stderrdata) = self.process.communicate(timeout=1) + except subprocess.TimeoutExpired: + pass + + try: + self.stdoutdata = self.stdoutdata.decode("utf-8") + self.stderrdata = self.stderrdata.decode("utf-8") + except AttributeError: + pass if (now - self.check_time) > self.timeout: logger.warning("Process pid=%d spent too much time: %d s", self.process.pid, now - self.check_time) - self.kill__() + self.kill() self.status = 'timeout' self.execution_time = now - self.check_time self.exit_status = 3 - # Do not keep a pointer to the process - # todo: ??? + + # Do not keep the process objcet del self.process + # Get the user and system time _, _, n_child_utime, n_child_stime, _ = os.times() self.u_time = n_child_utime - child_utime @@ -340,49 +405,56 @@ def check_finished(self, max_plugins_output_length): return logger.debug("Process pid=%d exited with %d", self.process.pid, self.process.returncode) - # Get standards outputs from the communicate function if we do - # not have the fcntl module (Windows, and maybe some special - # unix like AIX) - if not fcntl: - (self.stdoutdata, self.stderrdata) = self.process.communicate() - else: - # The command was too quick and finished even before we can - # poll it first. So finish the read. - self.stdoutdata += no_block_read(self.process.stdout) - self.stderrdata += no_block_read(self.process.stderr) + print("Process pid=%d exited with %d" %(self.process.pid, self.process.returncode)) self.exit_status = self.process.returncode + print("Exit code: %s" % self.exit_status) if self.log_actions: if os.environ['ALIGNAK_LOG_ACTIONS'] == 'WARNING': - logger.warning("Action '%s' exited with return code %d", - self.command, self.exit_status) + logger.warning("Action '%s' exited with code %d", self.command, self.exit_status) else: - logger.info("Action '%s' exited with return code %d", - self.command, self.exit_status) + logger.info("Action '%s' exited with code %d", self.command, self.exit_status) - # we should not keep the process now - # todo: ??? - del self.process + (self.stdoutdata, self.stderrdata) = self.process.communicate() + try: + self.stdoutdata = self.stdoutdata.decode("utf-8") + self.stderrdata = self.stderrdata.decode("utf-8") + except AttributeError: + pass - if ( # check for bad syntax in command line: - 'sh: -c: line 0: unexpected EOF while looking for matching' in self.stderrdata or - ('sh: -c:' in self.stderrdata and ': Syntax' in self.stderrdata) or - 'Syntax error: Unterminated quoted string' in self.stderrdata - ): - logger.warning("Return bad syntax in command line!") - # Very, very ugly. But subprocess._handle_exitstatus does - # not see a difference between a regular "exit 1" and a - # bailing out shell. Strange, because strace clearly shows - # a difference. (exit_group(1) vs. exit_group(257)) - self.stdoutdata = self.stdoutdata + self.stderrdata - self.exit_status = 3 + print("Stdout: %s" % self.stdoutdata) + print("Stderr: %s" % self.stderrdata) + + # We do not need the process now + del self.process + # check for bad syntax in command line: + if (self.stderrdata.find('sh: -c: line 0: unexpected EOF') >= 0 or + (self.stderrdata.find('sh: -c: ') >= 0 and + self.stderrdata.find(': Syntax') >= 0 or + self.stderrdata.find('Syntax error: Unterminated quoted string') >= 0)): + print("Bad syntax: %s" % self.stderrdata) + logger.warning("Bad syntax in command line!") + # + # # Very, very ugly. But subprocess._handle_exitstatus does + # # not see a difference between a regular "exit 1" and a + # # bailing out shell. Strange, because strace clearly shows + # # a difference. (exit_group(1) vs. exit_group(257)) + # self.stdoutdata = self.stdoutdata + self.stderrdata + # self.exit_status = 3 + + # Make sure that exit code is a valid exit code if self.exit_status not in VALID_EXIT_STATUS: self.exit_status = 3 - if not self.stdoutdata.strip(): + # Replace stdout with stderr if stdout is empty + self.stdoutdata = self.stdoutdata.strip() + if not self.stdoutdata: self.stdoutdata = self.stderrdata + print("Stdout: %s" % self.stdoutdata) + print("Stderr: %s" % self.stderrdata) + # Now grep what we want in the output self.get_outputs(self.stdoutdata, max_plugins_output_length) @@ -392,14 +464,14 @@ def check_finished(self, max_plugins_output_length): self.status = 'done' self.execution_time = time.time() - self.check_time + # Also get the system and user times _, _, n_child_utime, n_child_stime, _ = os.times() self.u_time = n_child_utime - child_utime self.s_time = n_child_stime - child_stime def copy_shell__(self, new_i): - """Copy all attributes listed in 'only_copy_prop' from `self` to - `new_i`. + """Create all attributes listed in 'ONLY_COPY_PROP' and return `self` with these attributes. :param new_i: object to :type new_i: object @@ -418,177 +490,23 @@ def got_shell_characters(self): :return: True if one shell character is found, False otherwise :rtype: bool """ - for character in SHELLCHARS: - if character in self.command: - return True - return False - - def execute__(self, force_shell=False): - """Execute action in a subprocess - - :return: None - """ - pass + return any(c in SHELLCHARS for c in self.command) - def kill__(self): + def kill(self): """Kill the action and close fds - :return: None - """ - pass - -# OS specific "execute__" & "kill__" are defined by "Action" class -# definition: -# - - -if os.name != 'nt': - - class Action(ActionBase): - """Action class for *NIX systems + :return: None """ - - properties = ActionBase.properties.copy() - - def execute__(self, force_shell=sys.version_info < (2, 7)): - """Execute action in a subprocess - - :return: None or str: - 'toomanyopenfiles' if too many opened files on the system - 'no_process_launched' if arguments parsing failed - 'process_launch_failed': if the process launch failed - - TODO: Clean this - """ - # We allow direct launch only for 2.7 and higher version - # because if a direct launch crash, under this the file handles - # are not releases, it's not good. - - # If the command line got shell characters, we should go - # in a shell mode. So look at theses parameters - force_shell |= self.got_shell_characters() - - logger.debug("Action execute, force shell: %s", force_shell) - - # 2.7 and higher Python version need a list of args for cmd - # and if not force shell (if, it's useless, even dangerous) - # 2.4->2.6 accept just the string command - if sys.version_info < (2, 7) or force_shell: - cmd = self.command.encode('utf8', 'ignore') - else: - try: - cmd = shlex.split(self.command.encode('utf8', 'ignore')) - except Exception as exp: # pylint: disable=broad-except - self.output = 'Not a valid shell command: ' + exp.__str__() - self.exit_status = 3 - self.status = 'done' - self.execution_time = time.time() - self.check_time - return 'no_process_launched' - - # Now: GO for launch! - # logger.debug("Launching: %s" % (self.command.encode('utf8', 'ignore'))) - logger.debug("Action execute, cmd: %s", cmd) - - # The preexec_fn=os.setsid is set to give sons a same - # process group. See - # http://www.doughellmann.com/PyMOTW/subprocess/ for - # detail about this. + logger.debug("Action kill, cmd: %s", self.process.pid) + + # We kill a process group because we launched them with + # preexec_fn=os.setsid and so we can launch a whole kill + # tree instead of just the first one + os.killpg(self.process.pid, signal.SIGKILL) + # Try to force close the descriptors, because python seems to have problems with them + for file_d in [self.process.stdout, self.process.stderr]: try: - self.process = subprocess.Popen( - cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE, - close_fds=True, shell=force_shell, env=self.local_env, - preexec_fn=os.setsid) - - logger.debug("Action execute, process: %s", self.process.pid) - except OSError as exp: - logger.error("Fail launching command: %s, force shell: %s, OSError: %s", - self.command, force_shell, exp) - # Maybe it's just a shell we try to exec. So we must retry - if (not force_shell and exp.errno == 8 and - exp.strerror == 'Exec format error'): - logger.info("Retrying with forced shell...") - return self.execute__(True) - - self.output = exp.__str__() - self.exit_status = 2 - self.status = 'done' - self.execution_time = time.time() - self.check_time - - # Maybe we run out of file descriptor. It's not good at all! - if exp.errno == 24 and exp.strerror == 'Too many open files': - return 'toomanyopenfiles' - return 'process_launch_failed' + file_d.close() except Exception as exp: # pylint: disable=broad-except - logger.error("Fail launching command: %s, force shell: %s, exception: %s", - self.command, force_shell, exp) - return 'process_launch_failed' - - return self.process - - def kill__(self): - """Kill the action and close fds - - :return: None - """ - logger.debug("Action kill, cmd: %s", self.process.pid) - - # We kill a process group because we launched them with - # preexec_fn=os.setsid and so we can launch a whole kill - # tree instead of just the first one - os.killpg(self.process.pid, signal.SIGKILL) - # Try to force close the descriptors, because python seems to have problems with them - for file_d in [self.process.stdout, self.process.stderr]: - try: - file_d.close() - except Exception as exp: # pylint: disable=broad-except - logger.error("Exception stopping command: %s %s", - self.command, exp) - - -else: # pragma: no cover, not currently tested with Windows... - - import ctypes # pylint: disable=C0411,C0413 - - class Action(ActionBase): - """Action class for Windows systems - - """ - - properties = ActionBase.properties.copy() - - def execute__(self, force_shell=False): - """Execute action in a subprocess - - :return: None - """ - # 2.7 and higher Python version need a list of args for cmd - # 2.4->2.6 accept just the string command - if sys.version_info < (2, 7): - cmd = self.command - else: - try: - cmd = shlex.split(self.command.encode('utf8', 'ignore')) - except Exception as exp: # pylint: disable=broad-except - self.output = 'Not a valid shell command: ' + exp.__str__() - self.exit_status = 3 - self.status = 'done' - self.execution_time = time.time() - self.check_time - return - - try: - self.process = subprocess.Popen( - cmd, stdout=subprocess.PIPE, stderr=subprocess.PIPE, - env=self.local_env, shell=True) - except WindowsError as exp: # pylint: disable=E0602 - logger.info("We kill the process: %s %s", exp, self.command) - self.status = 'timeout' - self.execution_time = time.time() - self.check_time - - def kill__(self): - """Wrapped to call TerminateProcess + logger.error("Exception when stopping command: %s %s", self.command, str(exp)) - :return: None - TODO: This look like python2.5 style. Maybe we change that. - """ - # pylint: disable=E1101 - ctypes.windll.kernel32.TerminateProcess(int(self.process._handle), -1) diff --git a/alignak/objects/config.py b/alignak/objects/config.py index 7fce5d153..3784787b2 100644 --- a/alignak/objects/config.py +++ b/alignak/objects/config.py @@ -1005,7 +1005,6 @@ def read_config(self, files): # just a first pass to get the cfg_file and all files in a buf res = StringIO() - # Make sure the configuration files are not repeated... if not self.read_config_silent and files: logger.info("Reading the configuration files...") for c_file in files: @@ -1017,8 +1016,12 @@ def read_config(self, files): # We add a \n (or \r\n) to be sure config files are separated # if the previous does not finish with a line return - res.write(os.linesep) - res.write('# IMPORTEDFROM=%s' % (c_file) + os.linesep) + try: + res.write(os.linesep) + res.write('# IMPORTEDFROM=%s' % (c_file) + os.linesep) + except TypeError: + res.write(os.linesep) + res.write('# IMPORTEDFROM=%s' % (c_file) + os.linesep) if not self.read_config_silent: logger.info("- opening '%s' configuration file", c_file) try: diff --git a/alignak/property.py b/alignak/property.py index 9fc379715..b65790337 100644 --- a/alignak/property.py +++ b/alignak/property.py @@ -60,7 +60,7 @@ from alignak.util import to_float, to_split, to_char, to_int, unique_value, list_split __all__ = ('UnusedProp', 'BoolProp', 'IntegerProp', 'FloatProp', - 'CharProp', 'StringProp', 'ListProp', + 'CharProp', 'StringProp', 'ListProp', 'DictProp', 'FULL_STATUS', 'CHECK_RESULT') # Suggestion diff --git a/test/cfg/run_realms/alignak.ini b/test/cfg/run_realms/alignak.ini index 33eda6274..7b8e3761a 100755 --- a/test/cfg/run_realms/alignak.ini +++ b/test/cfg/run_realms/alignak.ini @@ -10,8 +10,8 @@ _dist_LOG=%(_dist)s config_name=Alignak configuration #-- Username and group to run (defaults to current user) -;;;;;user=alignak -;;;;;group=alignak +;;;;;;;;;user=alignak +;;;;;;;;;group=alignak # Disabling security means allowing the daemons to run under root account # idontcareaboutsecurity=0 diff --git a/test/cfg/run_realms_manage_sub_realms/alignak.ini b/test/cfg/run_realms_manage_sub_realms/alignak.ini index 085c9b449..33eda6274 100755 --- a/test/cfg/run_realms_manage_sub_realms/alignak.ini +++ b/test/cfg/run_realms_manage_sub_realms/alignak.ini @@ -10,8 +10,8 @@ _dist_LOG=%(_dist)s config_name=Alignak configuration #-- Username and group to run (defaults to current user) -;;;user=alignak -;;;group=alignak +;;;;;user=alignak +;;;;;group=alignak # Disabling security means allowing the daemons to run under root account # idontcareaboutsecurity=0 diff --git a/test/test_actions.py b/test/test_actions.py index e7a1b0a55..d37d21453 100644 --- a/test/test_actions.py +++ b/test/test_actions.py @@ -72,7 +72,7 @@ def setUp(self): assert a.timeout == 10 assert a.exit_status == 3 - def wait_finished(self, a, size=8012): + def wait_finished(self, a, size=8192): start = time.time() while True: # Do the job @@ -215,11 +215,7 @@ def test_action(self): :return: None """ a = Action() - - if os.name == 'nt': - a.command = r'libexec\\dummy_command.cmd' - else: - a.command = "libexec/dummy_command.sh" + a.command = "libexec/dummy_command.sh" assert a.got_shell_characters() == False @@ -386,24 +382,10 @@ def test_got_unclosed_quote(self): # Run the action script a.execute() - if sys.version_info < (2, 7): - # cygwin: /bin/sh: -c: line 0: unexpected EOF while looking for matching' - # ubuntu: /bin/sh: Syntax error: Unterminated quoted string - print(("Status: %s" % a.status)) - print(("Output: %s" % a.output)) - print(("Exit code: %s" % a.exit_status)) - - # Do not wait for end because it did not really started ... - # Todo: Python 2.6 different behavior ... but it will be deprecated soon, - # so do not care with this now - assert 'launched' == a.status - assert "" == a.output - assert 3 == a.exit_status - else: - # Do not wait for end because it did not really started ... - assert 'done' == a.status - assert 'Not a valid shell command: No closing quotation' == a.output - assert 3 == a.exit_status + # Do not wait for end because it did not really started ... + assert 'done' == a.status + assert 'Not a valid shell command: No closing quotation' == a.output + assert 3 == a.exit_status def test_huge_output(self): """ Test huge output @@ -419,13 +401,7 @@ def test_huge_output(self): a = Action() a.timeout = 5 - - if os.name == 'nt': - a.command = r"""python -c 'print "A"*%d'""" % max_output_length - # Todo: As of now, it fails on Windows:( - return - else: - a.command = r"""python -u -c 'print "."*%d'""" % max_output_length + a.command = r"""python -u -c 'print "."*%d'""" % max_output_length ### ### 1 - output is less than the max output